[==========] 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:20:15.378113 11220 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.245.62:44323
I20260812 06:20:15.379181 11220 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:20:15.379804 11220 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:15.387388 11225 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:15.387459 11220 server_base.cc:1061] running on GCE node
W20260812 06:20:15.387388 11226 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:15.387677 11228 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:15.388338 11220 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:15.388468 11220 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:20:15.388517 11220 hybrid_clock.cc:648] HybridClock initialized: now 1786515615388513 us; error 0 us; skew 500 ppm
I20260812 06:20:15.390437 11220 webserver.cc:533] Webserver started at http://127.10.245.62:33919/ using document root <none> and password file <none>
I20260812 06:20:15.391045 11220 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:15.391106 11220 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:15.391305 11220 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:15.393077 11220 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/master-0-root/instance:
uuid: "542087a47ef245639ba773574e85590d"
format_stamp: "Formatted at 2026-08-12 06:20:15 on dist-test-slave-1jjb"
I20260812 06:20:15.396652 11220 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.001s
I20260812 06:20:15.398739 11234 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:15.399763 11220 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:15.399861 11220 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/master-0-root
uuid: "542087a47ef245639ba773574e85590d"
format_stamp: "Formatted at 2026-08-12 06:20:15 on dist-test-slave-1jjb"
I20260812 06:20:15.399945 11220 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-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:20:15.414366 11220 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:15.415009 11220 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:20:15.415146 11220 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:15.423087 11220 rpc_server.cc:307] RPC server started. Bound to: 127.10.245.62:44323
I20260812 06:20:15.423172 11294 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.245.62:44323 every 8 connection(s)
I20260812 06:20:15.425670 11295 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:20:15.431143 11295 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d: Bootstrap starting.
I20260812 06:20:15.433634 11295 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:15.434546 11295 log.cc:826] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:15.436353 11295 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d: No bootstrap required, opened a new log
I20260812 06:20:15.439169 11295 raft_consensus.cc:359] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "542087a47ef245639ba773574e85590d" member_type: VOTER }
I20260812 06:20:15.439343 11295 raft_consensus.cc:385] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:15.439400 11295 raft_consensus.cc:740] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 542087a47ef245639ba773574e85590d, State: Initialized, Role: FOLLOWER
I20260812 06:20:15.439960 11295 consensus_queue.cc:260] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [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: "542087a47ef245639ba773574e85590d" member_type: VOTER }
I20260812 06:20:15.440155 11295 raft_consensus.cc:399] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:15.440228 11295 raft_consensus.cc:493] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:15.440325 11295 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:15.441133 11295 raft_consensus.cc:515] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "542087a47ef245639ba773574e85590d" member_type: VOTER }
I20260812 06:20:15.441546 11295 leader_election.cc:304] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [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: 542087a47ef245639ba773574e85590d; no voters: 
I20260812 06:20:15.441826 11295 leader_election.cc:290] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:15.441942 11298 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:15.442225 11298 raft_consensus.cc:697] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [term 1 LEADER]: Becoming Leader. State: Replica: 542087a47ef245639ba773574e85590d, State: Running, Role: LEADER
I20260812 06:20:15.442637 11298 consensus_queue.cc:237] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [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: "542087a47ef245639ba773574e85590d" member_type: VOTER }
I20260812 06:20:15.442924 11295 sys_catalog.cc:565] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:15.444603 11299 sys_catalog.cc:455] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 542087a47ef245639ba773574e85590d. Latest consensus state: current_term: 1 leader_uuid: "542087a47ef245639ba773574e85590d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "542087a47ef245639ba773574e85590d" member_type: VOTER } }
I20260812 06:20:15.444644 11300 sys_catalog.cc:455] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "542087a47ef245639ba773574e85590d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "542087a47ef245639ba773574e85590d" member_type: VOTER } }
I20260812 06:20:15.444720 11299 sys_catalog.cc:458] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:15.444743 11300 sys_catalog.cc:458] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:15.445392 11220 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:20:15.447275 11316 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:15.447368 11316 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:15.447454 11309 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:15.448323 11309 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:15.453377 11309 catalog_manager.cc:1383] Generated new cluster ID: ea4a820307a94bdc906a1d9a2cfd222c
I20260812 06:20:15.453452 11309 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:15.466305 11309 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:15.467216 11309 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:15.480913 11309 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d: Generated new TSK 0
I20260812 06:20:15.481652 11309 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:15.510432 11220 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:15.513463 11323 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:20:15.513556 11326 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:20:15.513664 11220 server_base.cc:1061] running on GCE node
W20260812 06:20:15.513492 11320 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:20:15.514019 11220 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:15.514089 11220 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:20:15.514120 11220 hybrid_clock.cc:648] HybridClock initialized: now 1786515615514119 us; error 0 us; skew 500 ppm
I20260812 06:20:15.515093 11220 webserver.cc:533] Webserver started at http://127.10.245.1:45249/ using document root <none> and password file <none>
I20260812 06:20:15.515281 11220 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:15.515367 11220 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:15.515479 11220 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:15.515892 11220 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/instance:
uuid: "7ad6f3506bb04657bbf2f4725b11f525"
format_stamp: "Formatted at 2026-08-12 06:20:15 on dist-test-slave-1jjb"
I20260812 06:20:15.517508 11220 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:15.518627 11333 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:20:15.518879 11220 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:15.518953 11220 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root
uuid: "7ad6f3506bb04657bbf2f4725b11f525"
format_stamp: "Formatted at 2026-08-12 06:20:15 on dist-test-slave-1jjb"
I20260812 06:20:15.519057 11220 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-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:20:15.535012 11220 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:15.535543 11220 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:15.536126 11220 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:15.537115 11220 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:15.537170 11220 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:15.537240 11220 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:15.537281 11220 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:15.544391 11220 rpc_server.cc:307] RPC server started. Bound to: 127.10.245.1:44315
I20260812 06:20:15.544409 11403 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.245.1:44315 every 8 connection(s)
I20260812 06:20:15.558615 11404 heartbeater.cc:344] Connected to a master server at 127.10.245.62:44323
I20260812 06:20:15.558876 11404 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:15.559350 11404 heartbeater.cc:507] Master 127.10.245.62:44323 requested a full tablet report, sending...
I20260812 06:20:15.560877 11254 ts_manager.cc:194] Registered new tserver with Master: 7ad6f3506bb04657bbf2f4725b11f525 (127.10.245.1:44315)
I20260812 06:20:15.561777 11220 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016681244s
I20260812 06:20:15.562173 11254 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:52120
I20260812 06:20:15.571493 11254 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:52128:
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:20:15.585426 11365 tablet_service.cc:1511] Processing CreateTablet for tablet cd4a6f8a346e4b24bd945f74c29b42db (DEFAULT_TABLE table=heavy-update-compaction-test [id=2a38c312e648470ab377d775c9a5d8d4]), partition=
I20260812 06:20:15.585970 11365 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet cd4a6f8a346e4b24bd945f74c29b42db. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:15.589527 11418 tablet_bootstrap.cc:492] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Bootstrap starting.
I20260812 06:20:15.590684 11418 tablet_bootstrap.cc:654] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:15.591899 11418 tablet_bootstrap.cc:492] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: No bootstrap required, opened a new log
I20260812 06:20:15.592022 11418 ts_tablet_manager.cc:1403] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:15.592495 11418 raft_consensus.cc:359] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ad6f3506bb04657bbf2f4725b11f525" member_type: VOTER last_known_addr { host: "127.10.245.1" port: 44315 } }
I20260812 06:20:15.592615 11418 raft_consensus.cc:385] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:15.592664 11418 raft_consensus.cc:740] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7ad6f3506bb04657bbf2f4725b11f525, State: Initialized, Role: FOLLOWER
I20260812 06:20:15.592809 11418 consensus_queue.cc:260] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525 [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: "7ad6f3506bb04657bbf2f4725b11f525" member_type: VOTER last_known_addr { host: "127.10.245.1" port: 44315 } }
I20260812 06:20:15.592919 11418 raft_consensus.cc:399] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:15.592968 11418 raft_consensus.cc:493] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:15.593026 11418 raft_consensus.cc:3060] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:15.593753 11418 raft_consensus.cc:515] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ad6f3506bb04657bbf2f4725b11f525" member_type: VOTER last_known_addr { host: "127.10.245.1" port: 44315 } }
I20260812 06:20:15.593914 11418 leader_election.cc:304] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525 [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: 7ad6f3506bb04657bbf2f4725b11f525; no voters: 
I20260812 06:20:15.594147 11418 leader_election.cc:290] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:15.594264 11420 raft_consensus.cc:2804] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:15.594550 11420 raft_consensus.cc:697] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525 [term 1 LEADER]: Becoming Leader. State: Replica: 7ad6f3506bb04657bbf2f4725b11f525, State: Running, Role: LEADER
I20260812 06:20:15.594624 11418 ts_tablet_manager.cc:1434] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:20:15.595099 11404 heartbeater.cc:499] Master 127.10.245.62:44323 was elected leader, sending a full tablet report...
I20260812 06:20:15.594794 11420 consensus_queue.cc:237] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525 [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: "7ad6f3506bb04657bbf2f4725b11f525" member_type: VOTER last_known_addr { host: "127.10.245.1" port: 44315 } }
I20260812 06:20:15.598018 11254 catalog_manager.cc:5719] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525 reported cstate change: term changed from 0 to 1, leader changed from <none> to 7ad6f3506bb04657bbf2f4725b11f525 (127.10.245.1). New cstate: current_term: 1 leader_uuid: "7ad6f3506bb04657bbf2f4725b11f525" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ad6f3506bb04657bbf2f4725b11f525" member_type: VOTER last_known_addr { host: "127.10.245.1" port: 44315 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:15.664978 11220 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.015s	sys 0.012s
I20260812 06:20:15.795558 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushMRSOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=15.086190
I20260812 06:20:15.966161 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushMRSOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.170s	user 0.135s	sys 0.031s Metrics: {"bytes_written":12922855,"cfile_init":1,"compiler_manager_pool.queue_time_us":184,"delete_count":0,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":162,"dirs.run_wall_time_us":890,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41240,"lbm_writes_lt_1ms":682,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":138112,"thread_start_us":115,"threads_started":1,"update_count":1575}
I20260812 06:20:15.967442 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling LogGCOp(cd4a6f8a346e4b24bd945f74c29b42db): free 20743880 bytes of WAL
I20260812 06:20:15.967826 11338 log_reader.cc:385] T cd4a6f8a346e4b24bd945f74c29b42db: removed 2 log segments from log reader
I20260812 06:20:15.967918 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000001 (ops 1-6)
I20260812 06:20:15.967988 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000002 (ops 7-11)
I20260812 06:20:15.973762 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: LogGCOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:20:15.974157 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:15.989787 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3815488,"delete_count":0,"lbm_write_time_us":6084,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:20:15.990265 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling UndoDeltaBlockGCOp(cd4a6f8a346e4b24bd945f74c29b42db): 12719219 bytes on disk
I20260812 06:20:15.990885 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: UndoDeltaBlockGCOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:20:15.991357 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:16.000547 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.009s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3364205,"delete_count":0,"lbm_write_time_us":3468,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:20:16.001005 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:16.184098 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.183s	user 0.127s	sys 0.050s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364548,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":544,"lbm_read_time_us":15050,"lbm_reads_lt_1ms":559,"lbm_write_time_us":33706,"lbm_writes_lt_1ms":533,"mutex_wait_us":22,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":9728,"thread_start_us":313,"threads_started":5,"update_count":2450}
I20260812 06:20:16.184762 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=10.126437
I20260812 06:20:16.233789 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.049s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16758,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.234262 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:16.245448 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4038,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.246066 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:16.372519 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.126s	user 0.100s	sys 0.026s 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":1223,"lbm_read_time_us":9652,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23784,"lbm_writes_lt_1ms":443,"mutex_wait_us":349,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:20:16.373270 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=10.126437
I20260812 06:20:16.414844 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.041s	user 0.026s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17921,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.415367 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:16.430531 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5914,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.431201 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:16.552881 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.121s	user 0.098s	sys 0.023s 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":832,"lbm_read_time_us":9886,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22845,"lbm_writes_lt_1ms":443,"mutex_wait_us":122,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:16.553546 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=10.126437
I20260812 06:20:16.601257 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.047s	user 0.019s	sys 0.027s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16655,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.601909 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:16.613952 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4782,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.614390 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:16.769007 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.154s	user 0.105s	sys 0.039s 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":489,"lbm_read_time_us":11622,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25367,"lbm_writes_lt_1ms":443,"mutex_wait_us":332,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.769755 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=10.126437
I20260812 06:20:16.816411 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.046s	user 0.027s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18272,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.816844 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:16.828052 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4308,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.828732 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:16.957906 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.129s	user 0.093s	sys 0.034s 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":68,"lbm_read_time_us":9652,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26257,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2000}
I20260812 06:20:16.958524 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=10.126437
I20260812 06:20:16.993779 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.035s	user 0.016s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14703,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.994472 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:17.005695 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4295,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.006297 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:17.135923 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.129s	user 0.087s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1391,"lbm_read_time_us":10103,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24156,"lbm_writes_lt_1ms":443,"mutex_wait_us":409,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":47616,"update_count":2000}
I20260812 06:20:17.136722 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=10.126437
I20260812 06:20:17.176663 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.040s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15285,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.177155 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:17.187841 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4243,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.188392 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushMRSOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:17.218514 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushMRSOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.030s	user 0.025s	sys 0.003s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":313,"dirs.run_wall_time_us":1441,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1712,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:17.219391 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling LogGCOp(cd4a6f8a346e4b24bd945f74c29b42db): free 112239325 bytes of WAL
I20260812 06:20:17.219717 11338 log_reader.cc:385] T cd4a6f8a346e4b24bd945f74c29b42db: removed 11 log segments from log reader
I20260812 06:20:17.219776 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000003 (ops 12-16)
I20260812 06:20:17.219816 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000004 (ops 17-20)
I20260812 06:20:17.219854 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000005 (ops 21-25)
I20260812 06:20:17.219887 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000006 (ops 26-30)
I20260812 06:20:17.219916 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000007 (ops 31-35)
I20260812 06:20:17.219944 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000008 (ops 36-40)
I20260812 06:20:17.219973 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000009 (ops 41-45)
I20260812 06:20:17.220007 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000010 (ops 46-50)
I20260812 06:20:17.220043 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000011 (ops 51-55)
I20260812 06:20:17.220098 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000012 (ops 56-60)
I20260812 06:20:17.220131 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000013 (ops 61-65)
I20260812 06:20:17.249799 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: LogGCOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.030s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:20:17.250308 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling UndoDeltaBlockGCOp(cd4a6f8a346e4b24bd945f74c29b42db): 447 bytes on disk
I20260812 06:20:17.250841 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: UndoDeltaBlockGCOp(cd4a6f8a346e4b24bd945f74c29b42db) 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:20:17.251488 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:17.272940 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.021s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5417,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.273414 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:17.283731 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.010s	user 0.003s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4032,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.284269 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:17.468470 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.184s	user 0.145s	sys 0.034s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2217,"lbm_read_time_us":14274,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35776,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:20:17.468997 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=14.095187
I20260812 06:20:17.525431 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.056s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22120,"lbm_writes_lt_1ms":403,"mutex_wait_us":3,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.525920 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:17.538419 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4525,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.538901 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:17.716686 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.178s	user 0.137s	sys 0.034s 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":784,"lbm_read_time_us":11976,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36387,"lbm_writes_lt_1ms":543,"mutex_wait_us":388,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":87552,"update_count":2500}
I20260812 06:20:17.717324 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=14.095187
I20260812 06:20:17.763262 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.046s	user 0.018s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20195,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.763947 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:17.927181 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.163s	user 0.119s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":397,"lbm_read_time_us":9835,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26386,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2000}
I20260812 06:20:17.927770 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=14.095187
I20260812 06:20:17.982573 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.055s	user 0.014s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22569,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.983047 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:17.993716 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4086,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.994316 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:18.169917 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.175s	user 0.118s	sys 0.054s 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":835,"lbm_read_time_us":11078,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31900,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22272,"update_count":2500}
I20260812 06:20:18.170401 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=11.118625
I20260812 06:20:18.207883 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.037s	user 0.020s	sys 0.013s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":16446,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:18.208494 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:18.224150 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5129,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.224649 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:18.366426 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.142s	user 0.100s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":432,"lbm_read_time_us":9687,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28754,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:20:18.367079 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=10.126437
I20260812 06:20:18.414307 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.047s	user 0.034s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":20913,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.414933 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:18.430414 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.015s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5449,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.431077 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:18.567088 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.136s	user 0.094s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1447,"lbm_read_time_us":9859,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26605,"lbm_writes_lt_1ms":443,"mutex_wait_us":330,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2000}
I20260812 06:20:18.567667 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=11.118625
I20260812 06:20:18.604457 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.037s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14916,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:18.605314 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:18.623371 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.018s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5464,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.624131 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushMRSOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:18.664914 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushMRSOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.041s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":102,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":1457,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1833,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:18.665668 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=3.181125
I20260812 06:20:18.678915 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4834,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:18.679525 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling LogGCOp(cd4a6f8a346e4b24bd945f74c29b42db): free 120553382 bytes of WAL
I20260812 06:20:18.679783 11338 log_reader.cc:385] T cd4a6f8a346e4b24bd945f74c29b42db: removed 12 log segments from log reader
I20260812 06:20:18.679853 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000014 (ops 66-70)
I20260812 06:20:18.679904 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000015 (ops 71-75)
I20260812 06:20:18.679944 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000016 (ops 76-80)
I20260812 06:20:18.679989 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000017 (ops 81-85)
I20260812 06:20:18.680028 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000018 (ops 86-90)
I20260812 06:20:18.680091 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000019 (ops 91-94)
I20260812 06:20:18.680131 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000020 (ops 95-99)
I20260812 06:20:18.680166 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000021 (ops 100-104)
I20260812 06:20:18.680203 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000022 (ops 105-108)
I20260812 06:20:18.680243 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000023 (ops 109-113)
I20260812 06:20:18.680281 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000024 (ops 114-118)
I20260812 06:20:18.680320 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000025 (ops 119-123)
I20260812 06:20:18.706496 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: LogGCOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.027s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:20:18.706946 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:18.727116 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.020s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5897,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.727627 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling UndoDeltaBlockGCOp(cd4a6f8a346e4b24bd945f74c29b42db): 463 bytes on disk
I20260812 06:20:18.728142 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: UndoDeltaBlockGCOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:20:18.728760 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:18.739272 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4187,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.739786 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:18.935853 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.196s	user 0.142s	sys 0.051s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979847,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":3245,"dirs.run_cpu_time_us":701,"dirs.run_wall_time_us":3050,"lbm_read_time_us":15246,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39580,"lbm_writes_lt_1ms":743,"mutex_wait_us":2819,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6016,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:20:18.936606 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=14.095187
I20260812 06:20:18.978948 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.042s	user 0.028s	sys 0.012s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19238,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.979527 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:18.996217 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.016s	user 0.004s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6049,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":500}
I20260812 06:20:18.996838 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:19.156431 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.159s	user 0.123s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":661,"lbm_read_time_us":9870,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33374,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:19.157188 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=14.095187
I20260812 06:20:19.215485 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.058s	user 0.020s	sys 0.032s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":26254,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.215993 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:19.226536 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.226984 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:19.396214 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.169s	user 0.117s	sys 0.051s 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":827,"lbm_read_time_us":11603,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29426,"lbm_writes_lt_1ms":543,"mutex_wait_us":300,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:20:19.396730 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=14.095187
I20260812 06:20:19.451993 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.055s	user 0.024s	sys 0.022s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21985,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.452678 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:19.465839 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.013s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4800,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.466393 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:19.642809 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.176s	user 0.119s	sys 0.056s 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":360,"lbm_read_time_us":13832,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29867,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:19.644578 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=14.095187
I20260812 06:20:19.697691 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.053s	user 0.025s	sys 0.026s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20383,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.698333 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:19.710156 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4224,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.710655 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:19.884680 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.174s	user 0.106s	sys 0.059s 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":604,"lbm_read_time_us":13319,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":571,"lbm_write_time_us":29047,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:19.885389 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=14.095187
I20260812 06:20:19.944919 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.059s	user 0.023s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21106,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.945503 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:19.962141 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.016s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6311,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.962781 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:20.167820 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.205s	user 0.133s	sys 0.064s 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":548,"lbm_read_time_us":15637,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35505,"lbm_writes_lt_1ms":543,"mutex_wait_us":269,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:20:20.168613 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=10.126437
I20260812 06:20:20.233412 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.065s	user 0.029s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22599,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:20:20.234068 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:20.245654 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4437,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.246187 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushMRSOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:20.310582 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushMRSOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.064s	user 0.032s	sys 0.009s Metrics: {"bytes_written":1275445,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":1258,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1498,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31,"spinlock_wait_cycles":768}
I20260812 06:20:20.311600 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling LogGCOp(cd4a6f8a346e4b24bd945f74c29b42db): free 132571568 bytes of WAL
I20260812 06:20:20.311888 11338 log_reader.cc:385] T cd4a6f8a346e4b24bd945f74c29b42db: removed 13 log segments from log reader
I20260812 06:20:20.311942 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000026 (ops 124-128)
I20260812 06:20:20.311982 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000027 (ops 129-133)
I20260812 06:20:20.312018 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000028 (ops 134-138)
I20260812 06:20:20.312120 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000029 (ops 139-143)
I20260812 06:20:20.312160 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000030 (ops 144-148)
I20260812 06:20:20.312220 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000031 (ops 149-152)
I20260812 06:20:20.312256 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000032 (ops 153-157)
I20260812 06:20:20.312304 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000033 (ops 158-162)
I20260812 06:20:20.312337 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000034 (ops 163-167)
I20260812 06:20:20.312387 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000035 (ops 168-172)
I20260812 06:20:20.312424 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000036 (ops 173-176)
I20260812 06:20:20.312474 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000037 (ops 177-181)
I20260812 06:20:20.312506 11338 log.cc:1079] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/cd4a6f8a346e4b24bd945f74c29b42db/wal-000000038 (ops 182-186)
I20260812 06:20:20.349385 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: LogGCOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.038s	user 0.000s	sys 0.036s Metrics: {}
I20260812 06:20:20.349965 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:20.364287 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5704,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":500}
I20260812 06:20:20.364768 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling UndoDeltaBlockGCOp(cd4a6f8a346e4b24bd945f74c29b42db): 482 bytes on disk
I20260812 06:20:20.365168 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: UndoDeltaBlockGCOp(cd4a6f8a346e4b24bd945f74c29b42db) 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:20:20.365645 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:20.553006 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.187s	user 0.146s	sys 0.039s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774807,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":176,"lbm_read_time_us":14841,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":568,"lbm_write_time_us":30603,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12800,"thread_start_us":80,"threads_started":1,"update_count":2500}
I20260812 06:20:20.553731 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=14.095187
I20260812 06:20:20.602598 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.049s	user 0.033s	sys 0.007s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19259,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.603238 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=2.188937
I20260812 06:20:20.619127 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5971,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.619686 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=1.000000
I20260812 06:20:20.730110 11220 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.065s	user 1.842s	sys 0.147s
I20260812 06:20:20.807085 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: MajorDeltaCompactionOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.187s	user 0.142s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":277,"lbm_read_time_us":14248,"lbm_reads_lt_1ms":568,"lbm_write_time_us":30565,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":47104,"update_count":2500}
I20260812 06:20:20.807585 11406 maintenance_manager.cc:419] P 7ad6f3506bb04657bbf2f4725b11f525: Scheduling FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db): perf score=6.157687
I20260812 06:20:20.809517 11220 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.079s	user 0.003s	sys 0.000s
I20260812 06:20:20.810298 11220 tablet_server.cc:179] TabletServer@127.10.245.1:0 shutting down...
I20260812 06:20:20.830384 11338 maintenance_manager.cc:643] P 7ad6f3506bb04657bbf2f4725b11f525: FlushDeltaMemStoresOp(cd4a6f8a346e4b24bd945f74c29b42db) complete. Timing: real 0.023s	user 0.017s	sys 0.003s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9282,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:20.831081 11220 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:20.831568 11220 tablet_replica.cc:333] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525: stopping tablet replica
I20260812 06:20:20.831780 11220 raft_consensus.cc:2243] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:20.831979 11220 raft_consensus.cc:2272] T cd4a6f8a346e4b24bd945f74c29b42db P 7ad6f3506bb04657bbf2f4725b11f525 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:20.846767 11220 tablet_server.cc:196] TabletServer@127.10.245.1:0 shutdown complete.
I20260812 06:20:20.853641 11220 master.cc:562] Master@127.10.245.62:44323 shutting down...
I20260812 06:20:20.858212 11220 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:20.858373 11220 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:20.858428 11220 tablet_replica.cc:333] T 00000000000000000000000000000000 P 542087a47ef245639ba773574e85590d: stopping tablet replica
I20260812 06:20:20.871708 11220 master.cc:584] Master@127.10.245.62:44323 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5594 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:20.982583 11220 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.245.62:35569
I20260812 06:20:20.982975 11220 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:20.985320 11445 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:20:20.985399 11220 server_base.cc:1061] running on GCE node
W20260812 06:20:20.985497 11443 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:20:20.985595 11440 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:20:20.985816 11220 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:20.985877 11220 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:20:20.985901 11220 hybrid_clock.cc:648] HybridClock initialized: now 1786515620985901 us; error 0 us; skew 500 ppm
I20260812 06:20:20.986778 11220 webserver.cc:533] Webserver started at http://127.10.245.62:41071/ using document root <none> and password file <none>
I20260812 06:20:20.986966 11220 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:20.987042 11220 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:20.987123 11220 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:20.987547 11220 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/master-0-root/instance:
uuid: "2e34a25caf1f4ff08c3c56ddb876b4e9"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-1jjb"
I20260812 06:20:20.990051 11220 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:20.991037 11450 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:20:20.991329 11220 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:20.991425 11220 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/master-0-root
uuid: "2e34a25caf1f4ff08c3c56ddb876b4e9"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-1jjb"
I20260812 06:20:20.991513 11220 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-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:20:21.014613 11220 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:21.015033 11220 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:21.019338 11220 rpc_server.cc:307] RPC server started. Bound to: 127.10.245.62:35569
I20260812 06:20:21.021008 11512 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.245.62:35569 every 8 connection(s)
I20260812 06:20:21.021448 11513 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:20:21.023265 11513 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9: Bootstrap starting.
I20260812 06:20:21.024065 11513 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:21.025120 11513 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9: No bootstrap required, opened a new log
I20260812 06:20:21.025537 11513 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2e34a25caf1f4ff08c3c56ddb876b4e9" member_type: VOTER }
I20260812 06:20:21.025625 11513 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:21.025686 11513 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2e34a25caf1f4ff08c3c56ddb876b4e9, State: Initialized, Role: FOLLOWER
I20260812 06:20:21.025882 11513 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [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: "2e34a25caf1f4ff08c3c56ddb876b4e9" member_type: VOTER }
I20260812 06:20:21.025978 11513 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:21.026054 11513 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:21.026118 11513 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:21.026831 11513 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2e34a25caf1f4ff08c3c56ddb876b4e9" member_type: VOTER }
I20260812 06:20:21.027002 11513 leader_election.cc:304] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [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: 2e34a25caf1f4ff08c3c56ddb876b4e9; no voters: 
I20260812 06:20:21.027220 11513 leader_election.cc:290] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:21.027335 11516 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:21.027571 11516 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [term 1 LEADER]: Becoming Leader. State: Replica: 2e34a25caf1f4ff08c3c56ddb876b4e9, State: Running, Role: LEADER
I20260812 06:20:21.027709 11513 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:21.027738 11516 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [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: "2e34a25caf1f4ff08c3c56ddb876b4e9" member_type: VOTER }
I20260812 06:20:21.028231 11517 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2e34a25caf1f4ff08c3c56ddb876b4e9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2e34a25caf1f4ff08c3c56ddb876b4e9" member_type: VOTER } }
I20260812 06:20:21.028257 11518 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2e34a25caf1f4ff08c3c56ddb876b4e9. Latest consensus state: current_term: 1 leader_uuid: "2e34a25caf1f4ff08c3c56ddb876b4e9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2e34a25caf1f4ff08c3c56ddb876b4e9" member_type: VOTER } }
I20260812 06:20:21.028427 11518 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:21.028402 11517 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:21.028992 11523 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:21.029692 11523 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:21.029927 11220 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:21.031539 11523 catalog_manager.cc:1383] Generated new cluster ID: d24265f22bdd4891b857d56103b62c2f
I20260812 06:20:21.031595 11523 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:21.065965 11523 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:21.066577 11523 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:21.074671 11523 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9: Generated new TSK 0
I20260812 06:20:21.074859 11523 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:21.094489 11220 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:21.096464 11536 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:20:21.096585 11537 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:20:21.096617 11539 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:20:21.096925 11220 server_base.cc:1061] running on GCE node
I20260812 06:20:21.097128 11220 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:21.097172 11220 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:20:21.097188 11220 hybrid_clock.cc:648] HybridClock initialized: now 1786515621097188 us; error 0 us; skew 500 ppm
I20260812 06:20:21.098052 11220 webserver.cc:533] Webserver started at http://127.10.245.1:46293/ using document root <none> and password file <none>
I20260812 06:20:21.098199 11220 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:21.098284 11220 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:21.098356 11220 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:21.098726 11220 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/instance:
uuid: "6dd6cb283e154726a8a16c07665d0239"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-1jjb"
I20260812 06:20:21.100260 11220 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:21.101166 11547 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:20:21.101426 11220 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:21.101500 11220 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root
uuid: "6dd6cb283e154726a8a16c07665d0239"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-1jjb"
I20260812 06:20:21.101562 11220 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-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:20:21.115541 11220 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:21.115900 11220 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:21.116236 11220 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:21.116715 11220 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:21.116751 11220 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:21.116814 11220 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:21.116856 11220 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:21.121085 11220 rpc_server.cc:307] RPC server started. Bound to: 127.10.245.1:34527
I20260812 06:20:21.122272 11618 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.245.1:34527 every 8 connection(s)
I20260812 06:20:21.131162 11619 heartbeater.cc:344] Connected to a master server at 127.10.245.62:35569
I20260812 06:20:21.131309 11619 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:21.131572 11619 heartbeater.cc:507] Master 127.10.245.62:35569 requested a full tablet report, sending...
I20260812 06:20:21.132328 11472 ts_manager.cc:194] Registered new tserver with Master: 6dd6cb283e154726a8a16c07665d0239 (127.10.245.1:34527)
I20260812 06:20:21.132366 11220 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010191858s
I20260812 06:20:21.133351 11472 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48162
I20260812 06:20:21.139436 11472 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48172:
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:20:21.148239 11577 tablet_service.cc:1511] Processing CreateTablet for tablet 5eae106e5182492fbe4a4005c8ee57f5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=fff52d28d8834c54acb8590ae56ab764]), partition=
I20260812 06:20:21.148486 11577 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 5eae106e5182492fbe4a4005c8ee57f5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:21.150339 11632 tablet_bootstrap.cc:492] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Bootstrap starting.
I20260812 06:20:21.151243 11632 tablet_bootstrap.cc:654] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:21.152299 11632 tablet_bootstrap.cc:492] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: No bootstrap required, opened a new log
I20260812 06:20:21.152393 11632 ts_tablet_manager.cc:1403] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:21.152797 11632 raft_consensus.cc:359] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6dd6cb283e154726a8a16c07665d0239" member_type: VOTER last_known_addr { host: "127.10.245.1" port: 34527 } }
I20260812 06:20:21.152882 11632 raft_consensus.cc:385] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:21.152940 11632 raft_consensus.cc:740] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6dd6cb283e154726a8a16c07665d0239, State: Initialized, Role: FOLLOWER
I20260812 06:20:21.153108 11632 consensus_queue.cc:260] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239 [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: "6dd6cb283e154726a8a16c07665d0239" member_type: VOTER last_known_addr { host: "127.10.245.1" port: 34527 } }
I20260812 06:20:21.153184 11632 raft_consensus.cc:399] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:21.153242 11632 raft_consensus.cc:493] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:21.153287 11632 raft_consensus.cc:3060] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:21.154168 11632 raft_consensus.cc:515] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6dd6cb283e154726a8a16c07665d0239" member_type: VOTER last_known_addr { host: "127.10.245.1" port: 34527 } }
I20260812 06:20:21.154284 11632 leader_election.cc:304] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239 [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: 6dd6cb283e154726a8a16c07665d0239; no voters: 
I20260812 06:20:21.154433 11632 leader_election.cc:290] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:21.154548 11634 raft_consensus.cc:2804] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:21.154798 11634 raft_consensus.cc:697] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239 [term 1 LEADER]: Becoming Leader. State: Replica: 6dd6cb283e154726a8a16c07665d0239, State: Running, Role: LEADER
I20260812 06:20:21.154824 11619 heartbeater.cc:499] Master 127.10.245.62:35569 was elected leader, sending a full tablet report...
I20260812 06:20:21.154780 11632 ts_tablet_manager.cc:1434] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:21.154997 11634 consensus_queue.cc:237] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239 [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: "6dd6cb283e154726a8a16c07665d0239" member_type: VOTER last_known_addr { host: "127.10.245.1" port: 34527 } }
I20260812 06:20:21.156306 11472 catalog_manager.cc:5719] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239 reported cstate change: term changed from 0 to 1, leader changed from <none> to 6dd6cb283e154726a8a16c07665d0239 (127.10.245.1). New cstate: current_term: 1 leader_uuid: "6dd6cb283e154726a8a16c07665d0239" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6dd6cb283e154726a8a16c07665d0239" member_type: VOTER last_known_addr { host: "127.10.245.1" port: 34527 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:21.217401 11220 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.018s	sys 0.004s
I20260812 06:20:21.372785 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushMRSOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=19.054940
I20260812 06:20:21.525206 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushMRSOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.152s	user 0.110s	sys 0.041s Metrics: {"bytes_written":11897252,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":176,"dirs.run_wall_time_us":2495,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39982,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1450}
I20260812 06:20:21.525883 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling LogGCOp(5eae106e5182492fbe4a4005c8ee57f5): free 20743880 bytes of WAL
I20260812 06:20:21.526121 11552 log_reader.cc:385] T 5eae106e5182492fbe4a4005c8ee57f5: removed 2 log segments from log reader
I20260812 06:20:21.526186 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000001 (ops 1-6)
I20260812 06:20:21.526238 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000002 (ops 7-11)
I20260812 06:20:21.530948 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: LogGCOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.005s	user 0.002s	sys 0.000s Metrics: {}
I20260812 06:20:21.531291 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling UndoDeltaBlockGCOp(5eae106e5182492fbe4a4005c8ee57f5): 16821647 bytes on disk
I20260812 06:20:21.531720 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: UndoDeltaBlockGCOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.532178 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:21.553324 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.021s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5258,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.553778 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:21.719482 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.166s	user 0.130s	sys 0.028s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20303034,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":879,"lbm_read_time_us":9821,"lbm_reads_lt_1ms":450,"lbm_write_time_us":25296,"lbm_writes_lt_1ms":433,"mutex_wait_us":24,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":7680,"thread_start_us":377,"threads_started":5,"update_count":1950}
I20260812 06:20:21.720184 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=14.095187
I20260812 06:20:21.770599 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.050s	user 0.036s	sys 0.009s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22105,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.771107 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:21.784649 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.013s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4734,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.785183 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:21.938800 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.153s	user 0.123s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":718,"lbm_read_time_us":11737,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29215,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:20:21.939265 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=11.118625
I20260812 06:20:21.975868 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.036s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15786,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:21.976708 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:21.991973 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5666,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.992547 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:22.123266 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.131s	user 0.098s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1632,"lbm_read_time_us":10360,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25203,"lbm_writes_lt_1ms":443,"mutex_wait_us":449,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:20:22.124042 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=10.126437
I20260812 06:20:22.168864 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.045s	user 0.023s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20872,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.169303 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:22.180068 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4230,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.180771 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:22.309522 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.129s	user 0.100s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":550,"lbm_read_time_us":10801,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22793,"lbm_writes_lt_1ms":443,"mutex_wait_us":36,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2000}
I20260812 06:20:22.310006 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=10.126437
I20260812 06:20:22.353734 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.044s	user 0.011s	sys 0.029s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13925,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.354295 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:22.365293 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.011s	user 0.009s	sys 0.001s 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:20:22.365775 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:22.512933 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.147s	user 0.107s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":538,"lbm_read_time_us":11650,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24237,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2000}
I20260812 06:20:22.513540 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=10.126437
I20260812 06:20:22.556831 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.043s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15999,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.557413 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:22.568341 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4103,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.569113 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:22.702369 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.133s	user 0.092s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713274,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1361,"lbm_read_time_us":9477,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28539,"lbm_writes_lt_1ms":443,"mutex_wait_us":359,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2000}
I20260812 06:20:22.703105 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=10.126437
I20260812 06:20:22.745748 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.042s	user 0.034s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17424,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.746251 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:22.756834 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4167,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.757341 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushMRSOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:22.789436 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushMRSOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.032s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":200,"dirs.run_wall_time_us":2098,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1950,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:22.790014 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling LogGCOp(5eae106e5182492fbe4a4005c8ee57f5): free 112239259 bytes of WAL
I20260812 06:20:22.790233 11552 log_reader.cc:385] T 5eae106e5182492fbe4a4005c8ee57f5: removed 11 log segments from log reader
I20260812 06:20:22.790277 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000003 (ops 12-16)
I20260812 06:20:22.790304 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000004 (ops 17-21)
I20260812 06:20:22.790371 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000005 (ops 22-26)
I20260812 06:20:22.790416 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000006 (ops 27-31)
I20260812 06:20:22.790454 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000007 (ops 32-36)
I20260812 06:20:22.790480 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000008 (ops 37-40)
I20260812 06:20:22.790511 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000009 (ops 41-45)
I20260812 06:20:22.790535 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000010 (ops 46-50)
I20260812 06:20:22.790557 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000011 (ops 51-55)
I20260812 06:20:22.790587 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000012 (ops 56-60)
I20260812 06:20:22.790616 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000013 (ops 61-65)
I20260812 06:20:22.816097 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: LogGCOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.026s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:22.816463 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling UndoDeltaBlockGCOp(5eae106e5182492fbe4a4005c8ee57f5): 448 bytes on disk
I20260812 06:20:22.816903 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: UndoDeltaBlockGCOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:20:22.817380 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=3.181125
I20260812 06:20:22.830281 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.013s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4326,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:22.830684 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling LogGCOp(5eae106e5182492fbe4a4005c8ee57f5): free 12017983 bytes of WAL
I20260812 06:20:22.830873 11552 log_reader.cc:385] T 5eae106e5182492fbe4a4005c8ee57f5: removed 1 log segments from log reader
I20260812 06:20:22.830912 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000014 (ops 66-70)
I20260812 06:20:22.833478 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: LogGCOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:22.833753 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:22.844376 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.010s	user 0.004s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3559,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.844900 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:23.024066 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.179s	user 0.130s	sys 0.049s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918321,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":678,"lbm_read_time_us":12065,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35770,"lbm_writes_lt_1ms":643,"mutex_wait_us":31,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":98,"threads_started":1,"update_count":3000}
I20260812 06:20:23.024741 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=14.095187
I20260812 06:20:23.077819 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.053s	user 0.036s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23692,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.078330 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:23.090996 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4659,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.091468 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:23.253345 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.162s	user 0.115s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1414,"lbm_read_time_us":11430,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31073,"lbm_writes_lt_1ms":543,"mutex_wait_us":347,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:20:23.253916 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=14.095187
I20260812 06:20:23.299316 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.045s	user 0.018s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19820,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.299924 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:23.464427 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.164s	user 0.100s	sys 0.053s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":365,"lbm_read_time_us":9757,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26993,"lbm_writes_lt_1ms":443,"mutex_wait_us":61,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:20:23.469127 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=14.095187
I20260812 06:20:23.523768 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.054s	user 0.026s	sys 0.025s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":25152,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.524318 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:23.539255 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5916,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.539815 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:23.720793 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.181s	user 0.118s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":437,"lbm_read_time_us":11127,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27495,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:20:23.721410 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=14.095187
I20260812 06:20:23.771330 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.050s	user 0.043s	sys 0.004s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21370,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.772228 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:23.785204 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4602,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.785789 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:23.950062 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.164s	user 0.124s	sys 0.030s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":623,"lbm_read_time_us":12074,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29842,"lbm_writes_lt_1ms":543,"mutex_wait_us":306,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:20:23.950652 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=14.095187
I20260812 06:20:24.005398 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.054s	user 0.028s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26212,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.005937 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:24.018213 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4603,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.018663 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:24.175428 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.157s	user 0.133s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1206,"lbm_read_time_us":11170,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33461,"lbm_writes_lt_1ms":543,"mutex_wait_us":275,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:24.176281 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=11.118625
I20260812 06:20:24.218097 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.042s	user 0.018s	sys 0.021s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":17199,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:24.218770 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:24.234262 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.015s	user 0.003s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4222,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.234721 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:24.244400 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3575,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.244853 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushMRSOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:24.278602 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushMRSOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.034s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":273,"dirs.run_wall_time_us":1327,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2199,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:24.279218 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling LogGCOp(5eae106e5182492fbe4a4005c8ee57f5): free 116849514 bytes of WAL
I20260812 06:20:24.279441 11552 log_reader.cc:385] T 5eae106e5182492fbe4a4005c8ee57f5: removed 12 log segments from log reader
I20260812 06:20:24.279484 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000015 (ops 71-75)
I20260812 06:20:24.279512 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000016 (ops 76-80)
I20260812 06:20:24.279556 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000017 (ops 81-84)
I20260812 06:20:24.279598 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000018 (ops 85-89)
I20260812 06:20:24.279645 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000019 (ops 90-94)
I20260812 06:20:24.279690 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000020 (ops 95-98)
I20260812 06:20:24.279733 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000021 (ops 99-103)
I20260812 06:20:24.279772 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000022 (ops 104-108)
I20260812 06:20:24.279812 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000023 (ops 109-112)
I20260812 06:20:24.279852 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000024 (ops 113-117)
I20260812 06:20:24.279891 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000025 (ops 118-122)
I20260812 06:20:24.279929 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000026 (ops 123-127)
I20260812 06:20:24.308290 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: LogGCOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.029s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:20:24.308851 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=3.181125
I20260812 06:20:24.321707 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.013s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4836,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:24.322254 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling LogGCOp(5eae106e5182492fbe4a4005c8ee57f5): free 12017949 bytes of WAL
I20260812 06:20:24.322511 11552 log_reader.cc:385] T 5eae106e5182492fbe4a4005c8ee57f5: removed 1 log segments from log reader
I20260812 06:20:24.322570 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000027 (ops 128-132)
I20260812 06:20:24.325740 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: LogGCOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:24.326140 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:24.352341 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.026s	user 0.007s	sys 0.018s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5119,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.352851 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:24.580641 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.228s	user 0.118s	sys 0.109s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020841,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":277,"lbm_read_time_us":16015,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39493,"lbm_writes_lt_1ms":743,"mutex_wait_us":33,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":95,"threads_started":1,"update_count":3500}
I20260812 06:20:24.581352 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling UndoDeltaBlockGCOp(5eae106e5182492fbe4a4005c8ee57f5): 482 bytes on disk
I20260812 06:20:24.581849 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: UndoDeltaBlockGCOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":96,"lbm_reads_lt_1ms":4}
I20260812 06:20:24.582695 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=18.063937
I20260812 06:20:24.651948 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.069s	user 0.039s	sys 0.024s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":29642,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:24.652554 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:24.663326 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4343,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.663797 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:24.877471 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.213s	user 0.122s	sys 0.091s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":233,"lbm_read_time_us":16708,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33829,"lbm_writes_lt_1ms":643,"mutex_wait_us":91,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":3000}
I20260812 06:20:24.878347 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=14.095187
I20260812 06:20:24.926409 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.048s	user 0.037s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21841,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.926924 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:24.945227 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.018s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5486,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.945785 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:25.115886 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.170s	user 0.114s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":367,"lbm_read_time_us":11507,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30083,"lbm_writes_lt_1ms":543,"mutex_wait_us":83,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23168,"update_count":2500}
I20260812 06:20:25.116672 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=14.095187
I20260812 06:20:25.183557 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.067s	user 0.036s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24532,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.184240 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:25.202068 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.018s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6782,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.202735 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:25.378094 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.175s	user 0.125s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":436,"lbm_read_time_us":11382,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32161,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":33152,"update_count":2500}
I20260812 06:20:25.378794 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=14.095187
I20260812 06:20:25.437287 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.058s	user 0.042s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21169,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.438035 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:25.449134 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4335,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.449828 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:25.630689 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.181s	user 0.153s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":606,"lbm_read_time_us":13659,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29616,"lbm_writes_lt_1ms":543,"mutex_wait_us":297,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:20:25.631476 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=14.095187
I20260812 06:20:25.688999 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.057s	user 0.031s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18611,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.689599 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:25.706373 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.017s	user 0.005s	sys 0.010s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6444,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.707029 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushMRSOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:25.751830 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushMRSOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.045s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":176,"dirs.run_wall_time_us":1261,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1921,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:25.752521 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling LogGCOp(5eae106e5182492fbe4a4005c8ee57f5): free 108535684 bytes of WAL
I20260812 06:20:25.752738 11552 log_reader.cc:385] T 5eae106e5182492fbe4a4005c8ee57f5: removed 11 log segments from log reader
I20260812 06:20:25.752799 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000028 (ops 133-137)
I20260812 06:20:25.752851 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000029 (ops 138-142)
I20260812 06:20:25.752907 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000030 (ops 143-146)
I20260812 06:20:25.752947 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000031 (ops 147-151)
I20260812 06:20:25.752983 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000032 (ops 152-156)
I20260812 06:20:25.753019 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000033 (ops 157-161)
I20260812 06:20:25.753057 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000034 (ops 162-166)
I20260812 06:20:25.753093 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000035 (ops 167-171)
I20260812 06:20:25.753129 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000036 (ops 172-176)
I20260812 06:20:25.753165 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000037 (ops 177-180)
I20260812 06:20:25.753202 11552 log.cc:1079] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: Deleting log segment in path: /tmp/dist-test-taskZ6CRll/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515615362697-11220-0/minicluster-data/ts-0-root/wals/5eae106e5182492fbe4a4005c8ee57f5/wal-000000038 (ops 181-185)
I20260812 06:20:25.777321 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: LogGCOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:20:25.777889 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling UndoDeltaBlockGCOp(5eae106e5182492fbe4a4005c8ee57f5): 448 bytes on disk
I20260812 06:20:25.778420 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: UndoDeltaBlockGCOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.779055 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:25.804486 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.025s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5344,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.804963 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:25.819550 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.014s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5710,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.820155 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:26.076280 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.256s	user 0.159s	sys 0.087s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020743,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":411,"lbm_read_time_us":16202,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42540,"lbm_writes_lt_1ms":743,"mutex_wait_us":62,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":20864,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:20:26.077028 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=18.063937
I20260812 06:20:26.166798 11220 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.949s	user 1.784s	sys 0.200s
I20260812 06:20:26.170948 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.094s	user 0.046s	sys 0.020s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":31205,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:26.171408 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=2.188937
I20260812 06:20:26.181335 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: FlushDeltaMemStoresOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.010s	user 0.009s	sys 0.000s 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:20:26.181726 11620 maintenance_manager.cc:419] P 6dd6cb283e154726a8a16c07665d0239: Scheduling MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5): perf score=1.000000
I20260812 06:20:26.239570 11220 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.072s	user 0.001s	sys 0.000s
I20260812 06:20:26.240185 11220 tablet_server.cc:179] TabletServer@127.10.245.1:0 shutting down...
I20260812 06:20:26.331317 11552 maintenance_manager.cc:643] P 6dd6cb283e154726a8a16c07665d0239: MajorDeltaCompactionOp(5eae106e5182492fbe4a4005c8ee57f5) complete. Timing: real 0.149s	user 0.102s	sys 0.048s Metrics: {"cfile_cache_hit":225,"cfile_cache_hit_bytes":9193148,"cfile_cache_miss":407,"cfile_cache_miss_bytes":19724952,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":277,"lbm_read_time_us":8501,"lbm_reads_lt_1ms":439,"lbm_write_time_us":29373,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":74624,"update_count":3000}
I20260812 06:20:26.332134 11220 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:26.332420 11220 tablet_replica.cc:333] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239: stopping tablet replica
I20260812 06:20:26.332580 11220 raft_consensus.cc:2243] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:26.332751 11220 raft_consensus.cc:2272] T 5eae106e5182492fbe4a4005c8ee57f5 P 6dd6cb283e154726a8a16c07665d0239 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:26.347030 11220 tablet_server.cc:196] TabletServer@127.10.245.1:0 shutdown complete.
I20260812 06:20:26.384828 11220 master.cc:562] Master@127.10.245.62:35569 shutting down...
I20260812 06:20:26.388152 11220 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:26.388365 11220 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:26.388463 11220 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2e34a25caf1f4ff08c3c56ddb876b4e9: stopping tablet replica
I20260812 06:20:26.400934 11220 master.cc:584] Master@127.10.245.62:35569 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5528 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11124 ms total)

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