[==========] 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:17:37.391459 29916 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.55.62:45723
I20260812 06:17:37.392398 29916 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:17:37.392997 29916 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:37.399565 29925 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:17:37.399596 29924 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:17:37.399734 29916 server_base.cc:1061] running on GCE node
W20260812 06:17:37.399825 29927 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:17:37.400302 29916 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:37.400425 29916 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:17:37.400472 29916 hybrid_clock.cc:648] HybridClock initialized: now 1786515457400470 us; error 0 us; skew 500 ppm
I20260812 06:17:37.402300 29916 webserver.cc:533] Webserver started at http://127.29.55.62:36347/ using document root <none> and password file <none>
I20260812 06:17:37.402810 29916 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:37.402895 29916 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:37.403136 29916 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:37.404662 29916 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/master-0-root/instance:
uuid: "6a2588877e1e490d998bf91f542b5ad9"
format_stamp: "Formatted at 2026-08-12 06:17:37 on dist-test-slave-6nmv"
I20260812 06:17:37.408000 29916 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:17:37.410391 29934 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:17:37.411336 29916 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:37.411484 29916 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/master-0-root
uuid: "6a2588877e1e490d998bf91f542b5ad9"
format_stamp: "Formatted at 2026-08-12 06:17:37 on dist-test-slave-6nmv"
I20260812 06:17:37.411593 29916 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-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:17:37.427160 29916 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:37.427717 29916 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:17:37.427892 29916 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:37.435609 29916 rpc_server.cc:307] RPC server started. Bound to: 127.29.55.62:45723
I20260812 06:17:37.435613 29991 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.55.62:45723 every 8 connection(s)
I20260812 06:17:37.437963 29992 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:17:37.443634 29992 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9: Bootstrap starting.
I20260812 06:17:37.445958 29992 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:37.446839 29992 log.cc:826] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:37.448339 29992 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9: No bootstrap required, opened a new log
I20260812 06:17:37.451288 29992 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a2588877e1e490d998bf91f542b5ad9" member_type: VOTER }
I20260812 06:17:37.451507 29992 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:37.451563 29992 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6a2588877e1e490d998bf91f542b5ad9, State: Initialized, Role: FOLLOWER
I20260812 06:17:37.452193 29992 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [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: "6a2588877e1e490d998bf91f542b5ad9" member_type: VOTER }
I20260812 06:17:37.452342 29992 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:37.452406 29992 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:37.452504 29992 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:37.453290 29992 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a2588877e1e490d998bf91f542b5ad9" member_type: VOTER }
I20260812 06:17:37.453739 29992 leader_election.cc:304] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [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: 6a2588877e1e490d998bf91f542b5ad9; no voters: 
I20260812 06:17:37.454138 29992 leader_election.cc:290] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:37.454252 29995 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:37.454531 29995 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [term 1 LEADER]: Becoming Leader. State: Replica: 6a2588877e1e490d998bf91f542b5ad9, State: Running, Role: LEADER
I20260812 06:17:37.454984 29995 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [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: "6a2588877e1e490d998bf91f542b5ad9" member_type: VOTER }
I20260812 06:17:37.455341 29992 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:37.456833 29997 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6a2588877e1e490d998bf91f542b5ad9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a2588877e1e490d998bf91f542b5ad9" member_type: VOTER } }
I20260812 06:17:37.457007 29997 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:37.457381 30006 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:37.457928 29998 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6a2588877e1e490d998bf91f542b5ad9. Latest consensus state: current_term: 1 leader_uuid: "6a2588877e1e490d998bf91f542b5ad9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a2588877e1e490d998bf91f542b5ad9" member_type: VOTER } }
I20260812 06:17:37.458045 29998 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:37.459689 30006 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:37.460029 29916 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:37.464284 30006 catalog_manager.cc:1383] Generated new cluster ID: 3589e1f0a6dd4557b7cdb906589da015
I20260812 06:17:37.464346 30006 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:37.501134 30006 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:37.502329 30006 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:37.520895 30006 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9: Generated new TSK 0
I20260812 06:17:37.521543 30006 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:37.524586 29916 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:37.527064 30020 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:17:37.527122 30023 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:37.527153 30021 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:37.527352 29916 server_base.cc:1061] running on GCE node
I20260812 06:17:37.527541 29916 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:37.527596 29916 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:17:37.527628 29916 hybrid_clock.cc:648] HybridClock initialized: now 1786515457527627 us; error 0 us; skew 500 ppm
I20260812 06:17:37.528525 29916 webserver.cc:533] Webserver started at http://127.29.55.1:43071/ using document root <none> and password file <none>
I20260812 06:17:37.528687 29916 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:37.528748 29916 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:37.528815 29916 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:37.529155 29916 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/instance:
uuid: "8dc49526b6a4415da95ab56b32adb5ed"
format_stamp: "Formatted at 2026-08-12 06:17:37 on dist-test-slave-6nmv"
I20260812 06:17:37.530714 29916 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:37.531756 30028 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:17:37.532002 29916 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:37.532073 29916 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root
uuid: "8dc49526b6a4415da95ab56b32adb5ed"
format_stamp: "Formatted at 2026-08-12 06:17:37 on dist-test-slave-6nmv"
I20260812 06:17:37.532157 29916 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-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:17:37.542774 29916 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:37.543159 29916 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:37.543592 29916 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:37.544672 29916 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:37.544721 29916 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:37.544786 29916 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:37.544821 29916 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:37.551354 29916 rpc_server.cc:307] RPC server started. Bound to: 127.29.55.1:43481
I20260812 06:17:37.551398 30105 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.55.1:43481 every 8 connection(s)
I20260812 06:17:37.565012 30106 heartbeater.cc:344] Connected to a master server at 127.29.55.62:45723
I20260812 06:17:37.565248 30106 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:37.565742 30106 heartbeater.cc:507] Master 127.29.55.62:45723 requested a full tablet report, sending...
I20260812 06:17:37.567162 29951 ts_manager.cc:194] Registered new tserver with Master: 8dc49526b6a4415da95ab56b32adb5ed (127.29.55.1:43481)
I20260812 06:17:37.567951 29916 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015871536s
I20260812 06:17:37.568472 29951 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50478
I20260812 06:17:37.577950 29951 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50494:
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:17:37.593761 30061 tablet_service.cc:1511] Processing CreateTablet for tablet 154f2463d8f446aaa446ccf1556dcc15 (DEFAULT_TABLE table=heavy-update-compaction-test [id=a0cd5f8e5dbb49a78ebf85a927ba334f]), partition=
I20260812 06:17:37.594267 30061 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 154f2463d8f446aaa446ccf1556dcc15. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:37.596436 30120 tablet_bootstrap.cc:492] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Bootstrap starting.
I20260812 06:17:37.598084 30120 tablet_bootstrap.cc:654] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:37.599193 30120 tablet_bootstrap.cc:492] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: No bootstrap required, opened a new log
I20260812 06:17:37.599316 30120 ts_tablet_manager.cc:1403] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:37.599730 30120 raft_consensus.cc:359] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8dc49526b6a4415da95ab56b32adb5ed" member_type: VOTER last_known_addr { host: "127.29.55.1" port: 43481 } }
I20260812 06:17:37.599854 30120 raft_consensus.cc:385] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:37.599917 30120 raft_consensus.cc:740] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8dc49526b6a4415da95ab56b32adb5ed, State: Initialized, Role: FOLLOWER
I20260812 06:17:37.600075 30120 consensus_queue.cc:260] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed [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: "8dc49526b6a4415da95ab56b32adb5ed" member_type: VOTER last_known_addr { host: "127.29.55.1" port: 43481 } }
I20260812 06:17:37.600188 30120 raft_consensus.cc:399] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:37.600236 30120 raft_consensus.cc:493] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:37.600291 30120 raft_consensus.cc:3060] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:37.601338 30120 raft_consensus.cc:515] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8dc49526b6a4415da95ab56b32adb5ed" member_type: VOTER last_known_addr { host: "127.29.55.1" port: 43481 } }
I20260812 06:17:37.601493 30120 leader_election.cc:304] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed [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: 8dc49526b6a4415da95ab56b32adb5ed; no voters: 
I20260812 06:17:37.601738 30120 leader_election.cc:290] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:37.601877 30123 raft_consensus.cc:2804] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:37.602061 30123 raft_consensus.cc:697] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed [term 1 LEADER]: Becoming Leader. State: Replica: 8dc49526b6a4415da95ab56b32adb5ed, State: Running, Role: LEADER
I20260812 06:17:37.602173 30120 ts_tablet_manager.cc:1434] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:37.602437 30106 heartbeater.cc:499] Master 127.29.55.62:45723 was elected leader, sending a full tablet report...
I20260812 06:17:37.602258 30123 consensus_queue.cc:237] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed [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: "8dc49526b6a4415da95ab56b32adb5ed" member_type: VOTER last_known_addr { host: "127.29.55.1" port: 43481 } }
I20260812 06:17:37.605190 29951 catalog_manager.cc:5719] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed reported cstate change: term changed from 0 to 1, leader changed from <none> to 8dc49526b6a4415da95ab56b32adb5ed (127.29.55.1). New cstate: current_term: 1 leader_uuid: "8dc49526b6a4415da95ab56b32adb5ed" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8dc49526b6a4415da95ab56b32adb5ed" member_type: VOTER last_known_addr { host: "127.29.55.1" port: 43481 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:37.664640 29916 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.013s	sys 0.008s
I20260812 06:17:37.802659 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushMRSOp(154f2463d8f446aaa446ccf1556dcc15): perf score=19.054940
I20260812 06:17:37.979144 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushMRSOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.176s	user 0.142s	sys 0.032s Metrics: {"bytes_written":13497198,"cfile_init":1,"compiler_manager_pool.queue_time_us":198,"delete_count":0,"dirs.queue_time_us":33,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":911,"drs_written":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44689,"lbm_writes_lt_1ms":786,"mutex_wait_us":978,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":138624,"thread_start_us":134,"threads_started":1,"update_count":1645}
I20260812 06:17:37.980270 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling LogGCOp(154f2463d8f446aaa446ccf1556dcc15): free 20743880 bytes of WAL
I20260812 06:17:37.980657 30033 log_reader.cc:385] T 154f2463d8f446aaa446ccf1556dcc15: removed 2 log segments from log reader
I20260812 06:17:37.980741 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000001 (ops 1-6)
I20260812 06:17:37.980813 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000002 (ops 7-11)
I20260812 06:17:37.986266 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: LogGCOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:17:37.986613 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling UndoDeltaBlockGCOp(154f2463d8f446aaa446ccf1556dcc15): 16411393 bytes on disk
I20260812 06:17:37.987210 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: UndoDeltaBlockGCOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:17:37.987651 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=3.181125
I20260812 06:17:38.011368 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.024s	user 0.013s	sys 0.009s Metrics: {"bytes_written":4594951,"delete_count":0,"lbm_write_time_us":6896,"lbm_writes_lt_1ms":115,"reinsert_count":0,"update_count":560}
I20260812 06:17:38.011801 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.196750
I20260812 06:17:38.018821 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.007s	user 0.005s	sys 0.000s Metrics: {"bytes_written":2420629,"delete_count":0,"lbm_write_time_us":2503,"lbm_writes_lt_1ms":62,"reinsert_count":0,"update_count":295}
I20260812 06:17:38.019253 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:38.192332 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.173s	user 0.128s	sys 0.043s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774778,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":823,"lbm_read_time_us":13666,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29424,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":339,"threads_started":5,"update_count":2500}
I20260812 06:17:38.192842 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=11.118625
I20260812 06:17:38.220196 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.027s	user 0.017s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":12057,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:38.220580 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:38.233793 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4686,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:38.234406 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:38.358348 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.124s	user 0.097s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1751,"lbm_read_time_us":8314,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22959,"lbm_writes_lt_1ms":443,"mutex_wait_us":406,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:38.359112 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=11.118625
I20260812 06:17:38.393218 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.034s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":14330,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:38.393764 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:38.414942 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.021s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4746,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:38.415390 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:38.428946 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5588,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.429376 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:38.571199 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.142s	user 0.112s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774797,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":676,"lbm_read_time_us":10841,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27670,"lbm_writes_lt_1ms":543,"mutex_wait_us":303,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:17:38.571893 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=11.118625
I20260812 06:17:38.614276 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.042s	user 0.021s	sys 0.020s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":17718,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:38.615031 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:38.645051 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.030s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5718,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":450}
I20260812 06:17:38.645501 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:38.658855 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5429,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.659233 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:38.814175 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.155s	user 0.114s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":706,"lbm_read_time_us":11755,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26293,"lbm_writes_lt_1ms":543,"mutex_wait_us":267,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:17:38.815984 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=12.110812
I20260812 06:17:38.845988 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.030s	user 0.014s	sys 0.016s Metrics: {"bytes_written":13497271,"delete_count":0,"lbm_write_time_us":13621,"lbm_writes_lt_1ms":332,"reinsert_count":0,"update_count":1645}
I20260812 06:17:38.846467 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.196750
I20260812 06:17:38.865689 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.019s	user 0.012s	sys 0.001s Metrics: {"bytes_written":2912930,"delete_count":0,"lbm_write_time_us":4956,"lbm_writes_lt_1ms":74,"reinsert_count":0,"update_count":355}
I20260812 06:17:38.866178 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:39.010260 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.144s	user 0.113s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672329,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2475,"lbm_read_time_us":10148,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25015,"lbm_writes_lt_1ms":443,"mutex_wait_us":860,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:39.011009 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=11.118625
I20260812 06:17:39.042287 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.031s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12758765,"delete_count":0,"lbm_write_time_us":12909,"lbm_writes_lt_1ms":314,"reinsert_count":0,"update_count":1555}
I20260812 06:17:39.042752 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:39.067947 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.025s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":4861,"lbm_writes_lt_1ms":92,"reinsert_count":0,"spinlock_wait_cycles":46976,"update_count":445}
I20260812 06:17:39.068410 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:39.087136 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.019s	user 0.005s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3982,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.087699 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushMRSOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:39.116163 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushMRSOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.028s	user 0.020s	sys 0.005s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":1166,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1401,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:39.116838 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling LogGCOp(154f2463d8f446aaa446ccf1556dcc15): free 112239285 bytes of WAL
I20260812 06:17:39.117049 30033 log_reader.cc:385] T 154f2463d8f446aaa446ccf1556dcc15: removed 11 log segments from log reader
I20260812 06:17:39.117091 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000003 (ops 12-16)
I20260812 06:17:39.117116 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000004 (ops 17-21)
I20260812 06:17:39.117130 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000005 (ops 22-26)
I20260812 06:17:39.117185 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000006 (ops 27-30)
I20260812 06:17:39.117214 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000007 (ops 31-35)
I20260812 06:17:39.117249 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000008 (ops 36-40)
I20260812 06:17:39.117296 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000009 (ops 41-45)
I20260812 06:17:39.117336 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000010 (ops 46-50)
I20260812 06:17:39.117372 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000011 (ops 51-55)
I20260812 06:17:39.117419 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000012 (ops 56-60)
I20260812 06:17:39.117470 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000013 (ops 61-65)
I20260812 06:17:39.140197 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: LogGCOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.023s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:17:39.140564 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:39.162403 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.022s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6038,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.162842 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:39.172766 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3839,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.173172 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling UndoDeltaBlockGCOp(154f2463d8f446aaa446ccf1556dcc15): 448 bytes on disk
I20260812 06:17:39.173558 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: UndoDeltaBlockGCOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:17:39.174039 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:39.402310 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.228s	user 0.134s	sys 0.085s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979865,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":390,"lbm_read_time_us":14397,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39227,"lbm_writes_lt_1ms":743,"mutex_wait_us":17,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":23680,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:17:39.403007 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=18.063937
I20260812 06:17:39.468485 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.065s	user 0.042s	sys 0.012s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26176,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:39.468950 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:39.478986 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4016,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.479784 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:39.669198 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.189s	user 0.106s	sys 0.079s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":208,"lbm_read_time_us":13660,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32842,"lbm_writes_lt_1ms":643,"mutex_wait_us":1,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":32384,"update_count":3000}
I20260812 06:17:39.669755 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=15.087375
I20260812 06:17:39.720808 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.051s	user 0.027s	sys 0.021s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":22771,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:39.721417 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:39.735708 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5063,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:39.736121 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:39.901996 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.166s	user 0.109s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774676,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":235,"lbm_read_time_us":12345,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28791,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:17:39.902649 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=14.095187
I20260812 06:17:39.960830 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.058s	user 0.012s	sys 0.043s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21688,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.961330 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:39.972564 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4068,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.973001 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:40.140130 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.167s	user 0.116s	sys 0.043s 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":164,"lbm_read_time_us":11989,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27081,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:40.140714 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=14.095187
I20260812 06:17:40.198973 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.058s	user 0.040s	sys 0.014s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19937,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:40.199554 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:40.211151 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.011s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4575,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.211621 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:40.395954 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.184s	user 0.119s	sys 0.059s 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":1161,"lbm_read_time_us":13197,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30051,"lbm_writes_lt_1ms":543,"mutex_wait_us":343,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:40.396653 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=14.095187
I20260812 06:17:40.452708 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.056s	user 0.013s	sys 0.040s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27749,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:40.453230 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:40.477299 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.024s	user 0.006s	sys 0.014s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5786,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.477959 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushMRSOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:40.512090 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushMRSOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":1306,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1437,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:40.512768 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling LogGCOp(154f2463d8f446aaa446ccf1556dcc15): free 120553386 bytes of WAL
I20260812 06:17:40.512981 30033 log_reader.cc:385] T 154f2463d8f446aaa446ccf1556dcc15: removed 12 log segments from log reader
I20260812 06:17:40.513041 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000014 (ops 66-70)
I20260812 06:17:40.513094 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000015 (ops 71-75)
I20260812 06:17:40.513129 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000016 (ops 76-80)
I20260812 06:17:40.513164 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000017 (ops 81-84)
I20260812 06:17:40.513199 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000018 (ops 85-89)
I20260812 06:17:40.513237 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000019 (ops 90-94)
I20260812 06:17:40.513274 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000020 (ops 95-99)
I20260812 06:17:40.513312 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000021 (ops 100-104)
I20260812 06:17:40.513348 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000022 (ops 105-109)
I20260812 06:17:40.513386 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000023 (ops 110-114)
I20260812 06:17:40.513422 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000024 (ops 115-118)
I20260812 06:17:40.513458 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000025 (ops 119-123)
I20260812 06:17:40.540767 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: LogGCOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:40.541204 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=3.181125
I20260812 06:17:40.553365 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4152,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:40.553828 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:40.566416 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.012s	user 0.003s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5069,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:40.566792 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling UndoDeltaBlockGCOp(154f2463d8f446aaa446ccf1556dcc15): 447 bytes on disk
I20260812 06:17:40.567226 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: UndoDeltaBlockGCOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:17:40.567674 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:40.791565 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.224s	user 0.162s	sys 0.060s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979740,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":253,"lbm_read_time_us":14502,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39354,"lbm_writes_lt_1ms":743,"mutex_wait_us":58,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":95,"threads_started":1,"update_count":3500}
I20260812 06:17:40.792807 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=16.079562
I20260812 06:17:40.855619 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.063s	user 0.045s	sys 0.008s Metrics: {"bytes_written":17722676,"delete_count":0,"lbm_write_time_us":25456,"lbm_writes_lt_1ms":435,"reinsert_count":0,"update_count":2160}
I20260812 06:17:40.856034 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:40.865975 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3200109,"delete_count":0,"lbm_write_time_us":3118,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:17:40.866382 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:40.875355 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3503,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:40.875694 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:41.070405 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.195s	user 0.128s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877190,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":128,"lbm_read_time_us":14135,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31318,"lbm_writes_lt_1ms":643,"mutex_wait_us":27,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":3000}
I20260812 06:17:41.071485 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=16.079562
I20260812 06:17:41.118963 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.047s	user 0.035s	sys 0.011s Metrics: {"bytes_written":17558583,"delete_count":0,"lbm_write_time_us":20711,"lbm_writes_lt_1ms":431,"reinsert_count":0,"update_count":2140}
I20260812 06:17:41.119625 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.196750
I20260812 06:17:41.139264 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.019s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3159084,"delete_count":0,"lbm_write_time_us":3559,"lbm_writes_lt_1ms":80,"mutex_wait_us":34,"reinsert_count":0,"update_count":385}
I20260812 06:17:41.139720 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:41.148669 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":3615,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:17:41.149080 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:41.342752 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.194s	user 0.125s	sys 0.067s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877201,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1019,"lbm_read_time_us":12596,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34435,"lbm_writes_lt_1ms":643,"mutex_wait_us":353,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":27136,"update_count":3000}
I20260812 06:17:41.343583 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=14.095187
I20260812 06:17:41.402966 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.059s	user 0.030s	sys 0.028s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":25921,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:41.403465 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:41.417061 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4819,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.417471 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:41.588954 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.171s	user 0.112s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":252,"lbm_read_time_us":10830,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33487,"lbm_writes_lt_1ms":543,"mutex_wait_us":65,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:17:41.589558 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=14.095187
I20260812 06:17:41.648017 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.058s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19911,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:41.648537 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:41.659837 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4138,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.660300 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:41.837380 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.177s	user 0.106s	sys 0.064s 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":416,"lbm_read_time_us":11453,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32152,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21760,"update_count":2500}
I20260812 06:17:41.838136 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=14.095187
I20260812 06:17:41.898090 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.060s	user 0.030s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21679,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:41.898658 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:41.910174 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4398,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.910686 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushMRSOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:41.948922 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushMRSOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.038s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":1344,"drs_written":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1319,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:41.949600 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling LogGCOp(154f2463d8f446aaa446ccf1556dcc15): free 120553636 bytes of WAL
I20260812 06:17:41.949908 30033 log_reader.cc:385] T 154f2463d8f446aaa446ccf1556dcc15: removed 12 log segments from log reader
I20260812 06:17:41.949970 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000026 (ops 124-128)
I20260812 06:17:41.950003 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000027 (ops 129-133)
I20260812 06:17:41.950029 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000028 (ops 134-138)
I20260812 06:17:41.950058 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000029 (ops 139-142)
I20260812 06:17:41.950088 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000030 (ops 143-147)
I20260812 06:17:41.950114 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000031 (ops 148-152)
I20260812 06:17:41.950138 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000032 (ops 153-157)
I20260812 06:17:41.950158 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000033 (ops 158-162)
I20260812 06:17:41.950186 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000034 (ops 163-166)
I20260812 06:17:41.950213 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000035 (ops 167-171)
I20260812 06:17:41.950239 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000036 (ops 172-176)
I20260812 06:17:41.950265 30033 log.cc:1079] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/154f2463d8f446aaa446ccf1556dcc15/wal-000000037 (ops 177-181)
I20260812 06:17:41.979230 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: LogGCOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.029s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:17:41.980973 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling UndoDeltaBlockGCOp(154f2463d8f446aaa446ccf1556dcc15): 462 bytes on disk
I20260812 06:17:41.981405 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: UndoDeltaBlockGCOp(154f2463d8f446aaa446ccf1556dcc15) 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:17:41.982020 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=3.181125
I20260812 06:17:42.005342 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.023s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5701,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:42.005780 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:42.016249 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.010s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4018,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:42.016788 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:42.224117 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.207s	user 0.138s	sys 0.061s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979740,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":546,"lbm_read_time_us":15167,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35283,"lbm_writes_lt_1ms":743,"mutex_wait_us":33,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":69,"threads_started":1,"update_count":3500}
I20260812 06:17:42.225080 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=18.063937
I20260812 06:17:42.288085 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.063s	user 0.028s	sys 0.032s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28439,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:42.288582 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=2.188937
I20260812 06:17:42.299762 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3829,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.300352 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15): perf score=1.000000
I20260812 06:17:42.403015 29916 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.738s	user 1.660s	sys 0.188s
I20260812 06:17:42.447243 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: MajorDeltaCompactionOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.147s	user 0.125s	sys 0.020s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":11121,"lbm_reads_lt_1ms":668,"lbm_write_time_us":28798,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:17:42.447707 30107 maintenance_manager.cc:419] P 8dc49526b6a4415da95ab56b32adb5ed: Scheduling FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15): perf score=10.126437
I20260812 06:17:42.464468 29916 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.061s	user 0.004s	sys 0.000s
I20260812 06:17:42.465277 29916 tablet_server.cc:179] TabletServer@127.29.55.1:0 shutting down...
I20260812 06:17:42.487843 30033 maintenance_manager.cc:643] P 8dc49526b6a4415da95ab56b32adb5ed: FlushDeltaMemStoresOp(154f2463d8f446aaa446ccf1556dcc15) complete. Timing: real 0.040s	user 0.034s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17150,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:42.488371 29916 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:42.490120 29916 tablet_replica.cc:333] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed: stopping tablet replica
I20260812 06:17:42.490314 29916 raft_consensus.cc:2243] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:42.490491 29916 raft_consensus.cc:2272] T 154f2463d8f446aaa446ccf1556dcc15 P 8dc49526b6a4415da95ab56b32adb5ed [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:42.505234 29916 tablet_server.cc:196] TabletServer@127.29.55.1:0 shutdown complete.
I20260812 06:17:42.509444 29916 master.cc:562] Master@127.29.55.62:45723 shutting down...
I20260812 06:17:42.513355 29916 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:42.513520 29916 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:42.513614 29916 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6a2588877e1e490d998bf91f542b5ad9: stopping tablet replica
I20260812 06:17:42.525589 29916 master.cc:584] Master@127.29.55.62:45723 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5227 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:42.618649 29916 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.55.62:38947
I20260812 06:17:42.619067 29916 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:42.621124 30142 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:17:42.621177 29916 server_base.cc:1061] running on GCE node
W20260812 06:17:42.621205 30146 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:42.621426 30144 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:42.621640 29916 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:42.621701 29916 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:17:42.621735 29916 hybrid_clock.cc:648] HybridClock initialized: now 1786515462621734 us; error 0 us; skew 500 ppm
I20260812 06:17:42.622807 29916 webserver.cc:533] Webserver started at http://127.29.55.62:44311/ using document root <none> and password file <none>
I20260812 06:17:42.622987 29916 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:42.623047 29916 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:42.623119 29916 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:42.623463 29916 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/master-0-root/instance:
uuid: "132f2ce042dc40eda487c529cffe0fb2"
format_stamp: "Formatted at 2026-08-12 06:17:42 on dist-test-slave-6nmv"
I20260812 06:17:42.624765 29916 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:42.625633 30151 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:17:42.625902 29916 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:42.625993 29916 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/master-0-root
uuid: "132f2ce042dc40eda487c529cffe0fb2"
format_stamp: "Formatted at 2026-08-12 06:17:42 on dist-test-slave-6nmv"
I20260812 06:17:42.626075 29916 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-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:17:42.640456 29916 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:42.640776 29916 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:42.644855 29916 rpc_server.cc:307] RPC server started. Bound to: 127.29.55.62:38947
I20260812 06:17:42.648613 30218 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:17:42.652089 30217 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.55.62:38947 every 8 connection(s)
I20260812 06:17:42.664057 30218 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2: Bootstrap starting.
I20260812 06:17:42.664736 30218 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:42.665692 30218 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2: No bootstrap required, opened a new log
I20260812 06:17:42.666046 30218 raft_consensus.cc:359] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "132f2ce042dc40eda487c529cffe0fb2" member_type: VOTER }
I20260812 06:17:42.666123 30218 raft_consensus.cc:385] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:42.666144 30218 raft_consensus.cc:740] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 132f2ce042dc40eda487c529cffe0fb2, State: Initialized, Role: FOLLOWER
I20260812 06:17:42.666273 30218 consensus_queue.cc:260] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [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: "132f2ce042dc40eda487c529cffe0fb2" member_type: VOTER }
I20260812 06:17:42.666355 30218 raft_consensus.cc:399] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:42.666379 30218 raft_consensus.cc:493] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:42.666412 30218 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:42.666987 30218 raft_consensus.cc:515] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "132f2ce042dc40eda487c529cffe0fb2" member_type: VOTER }
I20260812 06:17:42.667092 30218 leader_election.cc:304] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [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: 132f2ce042dc40eda487c529cffe0fb2; no voters: 
I20260812 06:17:42.667218 30218 leader_election.cc:290] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:42.667384 30221 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:42.667557 30221 raft_consensus.cc:697] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [term 1 LEADER]: Becoming Leader. State: Replica: 132f2ce042dc40eda487c529cffe0fb2, State: Running, Role: LEADER
I20260812 06:17:42.667683 30218 sys_catalog.cc:565] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:42.667703 30221 consensus_queue.cc:237] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [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: "132f2ce042dc40eda487c529cffe0fb2" member_type: VOTER }
I20260812 06:17:42.668135 30222 sys_catalog.cc:455] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "132f2ce042dc40eda487c529cffe0fb2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "132f2ce042dc40eda487c529cffe0fb2" member_type: VOTER } }
I20260812 06:17:42.668203 30223 sys_catalog.cc:455] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 132f2ce042dc40eda487c529cffe0fb2. Latest consensus state: current_term: 1 leader_uuid: "132f2ce042dc40eda487c529cffe0fb2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "132f2ce042dc40eda487c529cffe0fb2" member_type: VOTER } }
I20260812 06:17:42.668332 30222 sys_catalog.cc:458] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:42.668345 30223 sys_catalog.cc:458] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:42.668933 30230 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:42.669541 30230 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:42.670809 29916 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:42.671473 30230 catalog_manager.cc:1383] Generated new cluster ID: 2e969ea9a99f49a7b2ed4dcd92e22986
I20260812 06:17:42.671535 30230 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:42.692682 30230 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:42.693233 30230 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:42.700107 30230 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2: Generated new TSK 0
I20260812 06:17:42.700263 30230 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:42.702950 29916 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:42.704772 30243 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:17:42.704856 30242 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:17:42.704826 30245 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:17:42.705065 29916 server_base.cc:1061] running on GCE node
I20260812 06:17:42.705205 29916 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:42.705240 29916 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:17:42.705253 29916 hybrid_clock.cc:648] HybridClock initialized: now 1786515462705254 us; error 0 us; skew 500 ppm
I20260812 06:17:42.706018 29916 webserver.cc:533] Webserver started at http://127.29.55.1:40143/ using document root <none> and password file <none>
I20260812 06:17:42.706140 29916 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:42.706176 29916 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:42.706221 29916 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:42.706525 29916 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/instance:
uuid: "ba88eab863df48018a4009ded3c2a9f9"
format_stamp: "Formatted at 2026-08-12 06:17:42 on dist-test-slave-6nmv"
I20260812 06:17:42.707800 29916 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:42.708611 30250 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:17:42.708859 29916 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:42.708925 29916 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root
uuid: "ba88eab863df48018a4009ded3c2a9f9"
format_stamp: "Formatted at 2026-08-12 06:17:42 on dist-test-slave-6nmv"
I20260812 06:17:42.708978 29916 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-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:17:42.714123 29916 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:42.714354 29916 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:42.714551 29916 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:42.714951 29916 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:42.714984 29916 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:42.715035 29916 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:42.715085 29916 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:42.718809 29916 rpc_server.cc:307] RPC server started. Bound to: 127.29.55.1:40545
I20260812 06:17:42.718884 30328 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.55.1:40545 every 8 connection(s)
I20260812 06:17:42.728870 30329 heartbeater.cc:344] Connected to a master server at 127.29.55.62:38947
I20260812 06:17:42.728965 30329 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:42.729139 30329 heartbeater.cc:507] Master 127.29.55.62:38947 requested a full tablet report, sending...
I20260812 06:17:42.729724 30171 ts_manager.cc:194] Registered new tserver with Master: ba88eab863df48018a4009ded3c2a9f9 (127.29.55.1:40545)
I20260812 06:17:42.730240 29916 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010989396s
I20260812 06:17:42.730525 30171 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41502
I20260812 06:17:42.736765 30171 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41516:
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:17:42.744504 30287 tablet_service.cc:1511] Processing CreateTablet for tablet bac3883c8afc4a8b96f43d018ea3b15e (DEFAULT_TABLE table=heavy-update-compaction-test [id=c972ea84acd648d9b1ceb28aabf1b727]), partition=
I20260812 06:17:42.744830 30287 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet bac3883c8afc4a8b96f43d018ea3b15e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:42.746628 30343 tablet_bootstrap.cc:492] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Bootstrap starting.
I20260812 06:17:42.747666 30343 tablet_bootstrap.cc:654] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:42.748534 30343 tablet_bootstrap.cc:492] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: No bootstrap required, opened a new log
I20260812 06:17:42.748598 30343 ts_tablet_manager.cc:1403] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:42.748900 30343 raft_consensus.cc:359] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ba88eab863df48018a4009ded3c2a9f9" member_type: VOTER last_known_addr { host: "127.29.55.1" port: 40545 } }
I20260812 06:17:42.749001 30343 raft_consensus.cc:385] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:42.749022 30343 raft_consensus.cc:740] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ba88eab863df48018a4009ded3c2a9f9, State: Initialized, Role: FOLLOWER
I20260812 06:17:42.749106 30343 consensus_queue.cc:260] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9 [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: "ba88eab863df48018a4009ded3c2a9f9" member_type: VOTER last_known_addr { host: "127.29.55.1" port: 40545 } }
I20260812 06:17:42.749159 30343 raft_consensus.cc:399] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:42.749179 30343 raft_consensus.cc:493] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:42.749205 30343 raft_consensus.cc:3060] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:42.749876 30343 raft_consensus.cc:515] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ba88eab863df48018a4009ded3c2a9f9" member_type: VOTER last_known_addr { host: "127.29.55.1" port: 40545 } }
I20260812 06:17:42.750001 30343 leader_election.cc:304] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9 [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: ba88eab863df48018a4009ded3c2a9f9; no voters: 
I20260812 06:17:42.750174 30343 leader_election.cc:290] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:42.750278 30345 raft_consensus.cc:2804] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:42.750492 30343 ts_tablet_manager.cc:1434] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:42.750458 30345 raft_consensus.cc:697] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9 [term 1 LEADER]: Becoming Leader. State: Replica: ba88eab863df48018a4009ded3c2a9f9, State: Running, Role: LEADER
I20260812 06:17:42.750635 30329 heartbeater.cc:499] Master 127.29.55.62:38947 was elected leader, sending a full tablet report...
I20260812 06:17:42.750784 30345 consensus_queue.cc:237] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9 [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: "ba88eab863df48018a4009ded3c2a9f9" member_type: VOTER last_known_addr { host: "127.29.55.1" port: 40545 } }
I20260812 06:17:42.752104 30171 catalog_manager.cc:5719] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9 reported cstate change: term changed from 0 to 1, leader changed from <none> to ba88eab863df48018a4009ded3c2a9f9 (127.29.55.1). New cstate: current_term: 1 leader_uuid: "ba88eab863df48018a4009ded3c2a9f9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ba88eab863df48018a4009ded3c2a9f9" member_type: VOTER last_known_addr { host: "127.29.55.1" port: 40545 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:42.807638 29916 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.013s	sys 0.008s
I20260812 06:17:42.969699 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushMRSOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=23.023690
I20260812 06:17:43.123493 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushMRSOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.154s	user 0.107s	sys 0.045s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":837,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45098,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:17:43.124508 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling LogGCOp(bac3883c8afc4a8b96f43d018ea3b15e): free 20743880 bytes of WAL
I20260812 06:17:43.124708 30255 log_reader.cc:385] T bac3883c8afc4a8b96f43d018ea3b15e: removed 2 log segments from log reader
I20260812 06:17:43.124756 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000001 (ops 1-6)
I20260812 06:17:43.124789 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000002 (ops 7-11)
I20260812 06:17:43.129360 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: LogGCOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:43.129695 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:43.153538 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.024s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6157,"lbm_writes_lt_1ms":103,"mutex_wait_us":2,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.153968 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling UndoDeltaBlockGCOp(bac3883c8afc4a8b96f43d018ea3b15e): 20513813 bytes on disk
I20260812 06:17:43.154330 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: UndoDeltaBlockGCOp(bac3883c8afc4a8b96f43d018ea3b15e) 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:17:43.154695 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:43.164084 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3760,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.164532 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:43.323448 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.159s	user 0.105s	sys 0.051s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815803,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":366,"lbm_read_time_us":13524,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29764,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"thread_start_us":288,"threads_started":5,"update_count":2500}
I20260812 06:17:43.324074 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=11.118625
I20260812 06:17:43.357262 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.033s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13825,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:43.357759 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:43.383499 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.026s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3848,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:43.383955 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:43.393651 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3932,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.394064 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:43.545511 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.151s	user 0.128s	sys 0.024s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":259,"lbm_read_time_us":12080,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29805,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:17:43.546248 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=10.126437
I20260812 06:17:43.583608 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.037s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15958,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:43.584072 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:43.598433 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5545,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.598943 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:43.717962 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.119s	user 0.109s	sys 0.008s 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":877,"lbm_read_time_us":8910,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21871,"lbm_writes_lt_1ms":443,"mutex_wait_us":374,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2000}
I20260812 06:17:43.718693 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=10.126437
I20260812 06:17:43.764786 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.046s	user 0.022s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14695,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:43.765481 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:43.775735 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4071,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.776171 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:43.918474 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.142s	user 0.086s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":857,"lbm_read_time_us":11726,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23075,"lbm_writes_lt_1ms":443,"mutex_wait_us":277,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2000}
I20260812 06:17:43.919165 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=10.126437
I20260812 06:17:43.957409 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.038s	user 0.029s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15874,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:43.957932 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:43.968921 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4216,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.969359 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:44.106629 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.137s	user 0.085s	sys 0.052s 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":160,"lbm_read_time_us":9403,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27885,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2000}
I20260812 06:17:44.107334 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=10.126437
I20260812 06:17:44.140141 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.032s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13970,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:44.140666 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:44.154978 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5402,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:44.155480 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:44.273301 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.118s	user 0.093s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":221,"lbm_read_time_us":8799,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21571,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2000}
I20260812 06:17:44.274029 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=10.126437
I20260812 06:17:44.311481 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.037s	user 0.031s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14859,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:44.312062 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:44.322520 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4183,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:44.322952 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushMRSOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:44.350805 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushMRSOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.028s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":1325,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1566,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:44.351397 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling LogGCOp(bac3883c8afc4a8b96f43d018ea3b15e): free 124710290 bytes of WAL
I20260812 06:17:44.351631 30255 log_reader.cc:385] T bac3883c8afc4a8b96f43d018ea3b15e: removed 12 log segments from log reader
I20260812 06:17:44.351675 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000003 (ops 12-16)
I20260812 06:17:44.351704 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000004 (ops 17-21)
I20260812 06:17:44.351769 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000005 (ops 22-26)
I20260812 06:17:44.351811 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000006 (ops 27-31)
I20260812 06:17:44.351857 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000007 (ops 32-36)
I20260812 06:17:44.351923 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000008 (ops 37-41)
I20260812 06:17:44.351964 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000009 (ops 42-46)
I20260812 06:17:44.352041 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000010 (ops 47-51)
I20260812 06:17:44.352079 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000011 (ops 52-56)
I20260812 06:17:44.352124 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000012 (ops 57-61)
I20260812 06:17:44.352164 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000013 (ops 62-66)
I20260812 06:17:44.352202 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000014 (ops 67-71)
I20260812 06:17:44.380816 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: LogGCOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:44.381270 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=3.181125
I20260812 06:17:44.398093 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6757,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:44.398432 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling UndoDeltaBlockGCOp(bac3883c8afc4a8b96f43d018ea3b15e): 473 bytes on disk
I20260812 06:17:44.398747 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: UndoDeltaBlockGCOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4}
I20260812 06:17:44.399124 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:44.407707 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.008s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3426,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:44.408164 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:44.585667 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.177s	user 0.152s	sys 0.024s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918324,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1152,"lbm_read_time_us":11569,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36513,"lbm_writes_lt_1ms":643,"mutex_wait_us":541,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19968,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:17:44.586443 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=14.095187
I20260812 06:17:44.638167 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.051s	user 0.032s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23086,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:44.638669 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:44.650800 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4730,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:44.651317 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:44.829277 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.178s	user 0.100s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":766,"lbm_read_time_us":13265,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34343,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":2500}
I20260812 06:17:44.829777 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=14.095187
I20260812 06:17:44.896205 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.066s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23420,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:44.896644 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:44.911005 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.014s	user 0.001s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5413,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:44.911564 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:45.073980 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.162s	user 0.131s	sys 0.028s 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":523,"lbm_read_time_us":12456,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26074,"lbm_writes_lt_1ms":543,"mutex_wait_us":249,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2500}
I20260812 06:17:45.074750 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=14.095187
I20260812 06:17:45.134424 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.059s	user 0.020s	sys 0.039s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22613,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:45.134898 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:45.144936 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4029,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:45.145303 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:45.310719 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.165s	user 0.125s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":360,"lbm_read_time_us":12545,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27684,"lbm_writes_lt_1ms":543,"mutex_wait_us":77,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:17:45.311223 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=11.118625
I20260812 06:17:45.343081 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.032s	user 0.023s	sys 0.007s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":13724,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:45.343649 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:45.363618 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.020s	user 0.012s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6363,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:45.364217 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:45.508198 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.144s	user 0.081s	sys 0.062s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713265,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":244,"lbm_read_time_us":9608,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22496,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:17:45.508883 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=14.095187
I20260812 06:17:45.564098 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.055s	user 0.024s	sys 0.025s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22389,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:45.564675 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:45.574837 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3795,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:45.575340 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:45.716646 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.141s	user 0.104s	sys 0.029s 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":154,"lbm_read_time_us":9150,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26883,"lbm_writes_lt_1ms":543,"mutex_wait_us":64,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2500}
I20260812 06:17:45.717278 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=14.095187
I20260812 06:17:45.768271 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.051s	user 0.019s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20266,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:45.768815 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:45.779445 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3909,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:45.780022 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushMRSOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:45.812244 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushMRSOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.032s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1323,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1431,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:45.812961 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling LogGCOp(bac3883c8afc4a8b96f43d018ea3b15e): free 133024394 bytes of WAL
I20260812 06:17:45.813221 30255 log_reader.cc:385] T bac3883c8afc4a8b96f43d018ea3b15e: removed 13 log segments from log reader
I20260812 06:17:45.813277 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000015 (ops 72-76)
I20260812 06:17:45.813313 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000016 (ops 77-80)
I20260812 06:17:45.813344 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000017 (ops 81-85)
I20260812 06:17:45.813381 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000018 (ops 86-90)
I20260812 06:17:45.813411 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000019 (ops 91-95)
I20260812 06:17:45.813441 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000020 (ops 96-100)
I20260812 06:17:45.813476 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000021 (ops 101-105)
I20260812 06:17:45.813504 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000022 (ops 106-110)
I20260812 06:17:45.813534 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000023 (ops 111-115)
I20260812 06:17:45.813563 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000024 (ops 116-120)
I20260812 06:17:45.813587 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000025 (ops 121-125)
I20260812 06:17:45.813611 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000026 (ops 126-130)
I20260812 06:17:45.813673 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000027 (ops 131-135)
I20260812 06:17:45.840924 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: LogGCOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:45.841387 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=6.157687
I20260812 06:17:45.867472 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.026s	user 0.015s	sys 0.009s Metrics: {"bytes_written":8082006,"delete_count":0,"lbm_write_time_us":11334,"lbm_writes_lt_1ms":200,"reinsert_count":0,"update_count":985}
I20260812 06:17:45.868028 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:46.086433 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.218s	user 0.136s	sys 0.069s Metrics: {"cfile_cache_miss":730,"cfile_cache_miss_bytes":32897555,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":3291,"lbm_read_time_us":11644,"lbm_reads_lt_1ms":766,"lbm_write_time_us":35332,"lbm_writes_lt_1ms":740,"mutex_wait_us":1462,"peak_mem_usage":86805555,"reinsert_count":0,"spinlock_wait_cycles":7680,"thread_start_us":75,"threads_started":1,"update_count":3485}
I20260812 06:17:46.087127 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=19.056125
I20260812 06:17:46.157272 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.070s	user 0.037s	sys 0.024s Metrics: {"bytes_written":20635393,"delete_count":0,"lbm_write_time_us":27539,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":505,"reinsert_count":0,"update_count":2515}
I20260812 06:17:46.157918 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling UndoDeltaBlockGCOp(bac3883c8afc4a8b96f43d018ea3b15e): 481 bytes on disk
I20260812 06:17:46.158361 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: UndoDeltaBlockGCOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:17:46.158987 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=3.181125
I20260812 06:17:46.179934 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.021s	user 0.001s	sys 0.013s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6687,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:46.180301 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:46.188781 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.008s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3442,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:46.189106 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:46.433815 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.245s	user 0.141s	sys 0.088s Metrics: {"cfile_cache_miss":736,"cfile_cache_miss_bytes":33143696,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":556,"lbm_read_time_us":15946,"lbm_reads_lt_1ms":776,"lbm_write_time_us":40500,"lbm_writes_lt_1ms":746,"mutex_wait_us":45,"peak_mem_usage":88092149,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":3515}
I20260812 06:17:46.434465 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=18.063937
I20260812 06:17:46.493793 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.059s	user 0.035s	sys 0.020s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":26458,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:46.494365 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:46.510949 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.016s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6514,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:46.511619 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:46.699525 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.188s	user 0.135s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":576,"lbm_read_time_us":12683,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34494,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3000}
I20260812 06:17:46.700227 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=14.095187
I20260812 06:17:46.778975 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.078s	user 0.024s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18206,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:46.779675 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:46.804407 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.025s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5479,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:46.804832 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:46.814595 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3958,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:46.814950 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:46.974990 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.160s	user 0.120s	sys 0.038s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918214,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":408,"lbm_read_time_us":12483,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31881,"lbm_writes_lt_1ms":643,"mutex_wait_us":19,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":3000}
I20260812 06:17:46.975560 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=14.095187
I20260812 06:17:47.018110 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.042s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18979,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:47.018610 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:47.031296 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4570,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.031957 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:47.189044 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.157s	user 0.125s	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":1161,"lbm_read_time_us":9356,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27980,"lbm_writes_lt_1ms":543,"mutex_wait_us":388,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":2500}
I20260812 06:17:47.189657 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=14.095187
I20260812 06:17:47.255522 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.066s	user 0.034s	sys 0.020s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":25068,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:47.256196 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:47.266283 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3877,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.267027 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushMRSOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:47.295889 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushMRSOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.029s	user 0.022s	sys 0.003s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":270,"dirs.run_wall_time_us":1363,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1473,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:47.296627 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling LogGCOp(bac3883c8afc4a8b96f43d018ea3b15e): free 124257514 bytes of WAL
I20260812 06:17:47.296905 30255 log_reader.cc:385] T bac3883c8afc4a8b96f43d018ea3b15e: removed 12 log segments from log reader
I20260812 06:17:47.296972 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000028 (ops 136-140)
I20260812 06:17:47.297003 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000029 (ops 141-145)
I20260812 06:17:47.297027 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000030 (ops 146-150)
I20260812 06:17:47.297076 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000031 (ops 151-154)
I20260812 06:17:47.297101 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000032 (ops 155-159)
I20260812 06:17:47.297122 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000033 (ops 160-164)
I20260812 06:17:47.297149 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000034 (ops 165-169)
I20260812 06:17:47.297183 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000035 (ops 170-174)
I20260812 06:17:47.297215 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000036 (ops 175-179)
I20260812 06:17:47.297246 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000037 (ops 180-184)
I20260812 06:17:47.297274 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000038 (ops 185-189)
I20260812 06:17:47.297302 30255 log.cc:1079] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: Deleting log segment in path: /tmp/dist-test-taskQFowVA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515457381471-29916-0/minicluster-data/ts-0-root/wals/bac3883c8afc4a8b96f43d018ea3b15e/wal-000000039 (ops 190-194)
I20260812 06:17:47.327842 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: LogGCOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:47.328256 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling UndoDeltaBlockGCOp(bac3883c8afc4a8b96f43d018ea3b15e): 482 bytes on disk
I20260812 06:17:47.328771 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: UndoDeltaBlockGCOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4}
I20260812 06:17:47.329663 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:47.352394 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.023s	user 0.000s	sys 0.012s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":5654,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.352861 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=2.188937
I20260812 06:17:47.363643 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: FlushDeltaMemStoresOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4448,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.364022 30330 maintenance_manager.cc:419] P ba88eab863df48018a4009ded3c2a9f9: Scheduling MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e): perf score=1.000000
I20260812 06:17:47.402616 29916 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.595s	user 1.722s	sys 0.143s
I20260812 06:17:47.484468 29916 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.081s	user 0.001s	sys 0.000s
I20260812 06:17:47.485008 29916 tablet_server.cc:179] TabletServer@127.29.55.1:0 shutting down...
I20260812 06:17:47.554147 30255 maintenance_manager.cc:643] P ba88eab863df48018a4009ded3c2a9f9: MajorDeltaCompactionOp(bac3883c8afc4a8b96f43d018ea3b15e) complete. Timing: real 0.190s	user 0.140s	sys 0.048s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020749,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1821,"lbm_read_time_us":15677,"lbm_reads_lt_1ms":770,"lbm_write_time_us":30768,"lbm_writes_lt_1ms":743,"mutex_wait_us":1097,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12544,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:17:47.554800 29916 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:47.555106 29916 tablet_replica.cc:333] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9: stopping tablet replica
I20260812 06:17:47.555269 29916 raft_consensus.cc:2243] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:47.555478 29916 raft_consensus.cc:2272] T bac3883c8afc4a8b96f43d018ea3b15e P ba88eab863df48018a4009ded3c2a9f9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:47.560894 29916 tablet_server.cc:196] TabletServer@127.29.55.1:0 shutdown complete.
I20260812 06:17:47.610894 29916 master.cc:562] Master@127.29.55.62:38947 shutting down...
I20260812 06:17:47.614804 29916 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:47.614955 29916 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:47.615006 29916 tablet_replica.cc:333] T 00000000000000000000000000000000 P 132f2ce042dc40eda487c529cffe0fb2: stopping tablet replica
I20260812 06:17:47.627143 29916 master.cc:584] Master@127.29.55.62:38947 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5092 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10320 ms total)

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