[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:50.546994 16319 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.239.254:45199
I20260812 06:18:50.548439 16319 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:50.549285 16319 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:50.556188 16319 server_base.cc:1061] running on GCE node
W20260812 06:18:50.556372 16330 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:50.556392 16335 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:50.556555 16328 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:18:50.557106 16319 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:50.557200 16319 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:50.557233 16319 hybrid_clock.cc:648] HybridClock initialized: now 1786515530557232 us; error 0 us; skew 500 ppm
I20260812 06:18:50.559180 16319 webserver.cc:533] Webserver started at http://127.15.239.254:33097/ using document root <none> and password file <none>
I20260812 06:18:50.559734 16319 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:50.559791 16319 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:50.560031 16319 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:50.561717 16319 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/master-0-root/instance:
uuid: "efdc969006de4b2ebdb2b27f36ec22cd"
format_stamp: "Formatted at 2026-08-12 06:18:50 on dist-test-slave-twwt"
I20260812 06:18:50.565737 16319 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.005s	sys 0.000s
I20260812 06:18:50.568279 16342 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:50.569427 16319 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:50.569566 16319 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/master-0-root
uuid: "efdc969006de4b2ebdb2b27f36ec22cd"
format_stamp: "Formatted at 2026-08-12 06:18:50 on dist-test-slave-twwt"
I20260812 06:18:50.569684 16319 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:50.584129 16319 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:50.584889 16319 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:50.585088 16319 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:50.593549 16319 rpc_server.cc:307] RPC server started. Bound to: 127.15.239.254:45199
I20260812 06:18:50.593559 16444 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.239.254:45199 every 8 connection(s)
I20260812 06:18:50.596181 16447 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:50.602072 16447 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd: Bootstrap starting.
I20260812 06:18:50.604857 16447 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:50.605837 16447 log.cc:826] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:50.607798 16447 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd: No bootstrap required, opened a new log
I20260812 06:18:50.610868 16447 raft_consensus.cc:359] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "efdc969006de4b2ebdb2b27f36ec22cd" member_type: VOTER }
I20260812 06:18:50.611068 16447 raft_consensus.cc:385] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:50.611123 16447 raft_consensus.cc:740] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: efdc969006de4b2ebdb2b27f36ec22cd, State: Initialized, Role: FOLLOWER
I20260812 06:18:50.611712 16447 consensus_queue.cc:260] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [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: "efdc969006de4b2ebdb2b27f36ec22cd" member_type: VOTER }
I20260812 06:18:50.611851 16447 raft_consensus.cc:399] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:50.611900 16447 raft_consensus.cc:493] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:50.612000 16447 raft_consensus.cc:3060] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:50.612836 16447 raft_consensus.cc:515] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "efdc969006de4b2ebdb2b27f36ec22cd" member_type: VOTER }
I20260812 06:18:50.613301 16447 leader_election.cc:304] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [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: efdc969006de4b2ebdb2b27f36ec22cd; no voters: 
I20260812 06:18:50.613627 16447 leader_election.cc:290] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:50.613824 16451 raft_consensus.cc:2804] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:50.614121 16451 raft_consensus.cc:697] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [term 1 LEADER]: Becoming Leader. State: Replica: efdc969006de4b2ebdb2b27f36ec22cd, State: Running, Role: LEADER
I20260812 06:18:50.614599 16451 consensus_queue.cc:237] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [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: "efdc969006de4b2ebdb2b27f36ec22cd" member_type: VOTER }
I20260812 06:18:50.614848 16447 sys_catalog.cc:565] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:50.617122 16454 sys_catalog.cc:455] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "efdc969006de4b2ebdb2b27f36ec22cd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "efdc969006de4b2ebdb2b27f36ec22cd" member_type: VOTER } }
I20260812 06:18:50.617130 16455 sys_catalog.cc:455] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [sys.catalog]: SysCatalogTable state changed. Reason: New leader efdc969006de4b2ebdb2b27f36ec22cd. Latest consensus state: current_term: 1 leader_uuid: "efdc969006de4b2ebdb2b27f36ec22cd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "efdc969006de4b2ebdb2b27f36ec22cd" member_type: VOTER } }
I20260812 06:18:50.617266 16454 sys_catalog.cc:458] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:50.617475 16319 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:50.617265 16455 sys_catalog.cc:458] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [sys.catalog]: This master's current role is: LEADER
W20260812 06:18:50.619768 16473 catalog_manager.cc:1594] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:50.619853 16473 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:50.619954 16476 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:50.620860 16476 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:50.625923 16476 catalog_manager.cc:1383] Generated new cluster ID: b70fd48feccb4c918fb7f42b4bb03a0f
I20260812 06:18:50.626015 16476 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:50.645798 16476 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:50.646963 16476 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:50.653347 16476 catalog_manager.cc:6092] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd: Generated new TSK 0
I20260812 06:18:50.654120 16476 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:50.682749 16319 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:50.685982 16489 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:50.686094 16484 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:50.686094 16483 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:18:50.686465 16319 server_base.cc:1061] running on GCE node
I20260812 06:18:50.686681 16319 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:50.686733 16319 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:50.686765 16319 hybrid_clock.cc:648] HybridClock initialized: now 1786515530686765 us; error 0 us; skew 500 ppm
I20260812 06:18:50.687808 16319 webserver.cc:533] Webserver started at http://127.15.239.193:38153/ using document root <none> and password file <none>
I20260812 06:18:50.687989 16319 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:50.688050 16319 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:50.688123 16319 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:50.688611 16319 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/instance:
uuid: "72c5715b6fcb400ca248c0a4801fd88f"
format_stamp: "Formatted at 2026-08-12 06:18:50 on dist-test-slave-twwt"
I20260812 06:18:50.690521 16319 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:50.691715 16496 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:50.691994 16319 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:50.692099 16319 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root
uuid: "72c5715b6fcb400ca248c0a4801fd88f"
format_stamp: "Formatted at 2026-08-12 06:18:50 on dist-test-slave-twwt"
I20260812 06:18:50.692198 16319 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:50.706893 16319 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:50.707401 16319 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:50.707998 16319 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:50.708979 16319 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:50.709056 16319 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:50.709137 16319 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:50.709188 16319 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:50.716424 16319 rpc_server.cc:307] RPC server started. Bound to: 127.15.239.193:45987
I20260812 06:18:50.716434 16602 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.239.193:45987 every 8 connection(s)
I20260812 06:18:50.727579 16605 heartbeater.cc:344] Connected to a master server at 127.15.239.254:45199
I20260812 06:18:50.727881 16605 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:50.728466 16605 heartbeater.cc:507] Master 127.15.239.254:45199 requested a full tablet report, sending...
I20260812 06:18:50.730119 16379 ts_manager.cc:194] Registered new tserver with Master: 72c5715b6fcb400ca248c0a4801fd88f (127.15.239.193:45987)
I20260812 06:18:50.730589 16319 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013501266s
I20260812 06:18:50.731745 16379 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34484
I20260812 06:18:50.740710 16379 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34488:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:50.757103 16543 tablet_service.cc:1511] Processing CreateTablet for tablet 9fdbcdbac35145bc9517fdb8ecd1960e (DEFAULT_TABLE table=heavy-update-compaction-test [id=835d156e516e42d0b761b2bfe40962a5]), partition=
I20260812 06:18:50.757622 16543 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 9fdbcdbac35145bc9517fdb8ecd1960e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:50.760211 16626 tablet_bootstrap.cc:492] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Bootstrap starting.
I20260812 06:18:50.761269 16626 tablet_bootstrap.cc:654] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:50.762864 16626 tablet_bootstrap.cc:492] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: No bootstrap required, opened a new log
I20260812 06:18:50.763006 16626 ts_tablet_manager.cc:1403] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:50.763514 16626 raft_consensus.cc:359] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "72c5715b6fcb400ca248c0a4801fd88f" member_type: VOTER last_known_addr { host: "127.15.239.193" port: 45987 } }
I20260812 06:18:50.763646 16626 raft_consensus.cc:385] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:50.763701 16626 raft_consensus.cc:740] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 72c5715b6fcb400ca248c0a4801fd88f, State: Initialized, Role: FOLLOWER
I20260812 06:18:50.763862 16626 consensus_queue.cc:260] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f [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: "72c5715b6fcb400ca248c0a4801fd88f" member_type: VOTER last_known_addr { host: "127.15.239.193" port: 45987 } }
I20260812 06:18:50.763991 16626 raft_consensus.cc:399] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:50.764083 16626 raft_consensus.cc:493] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:50.764146 16626 raft_consensus.cc:3060] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:50.764988 16626 raft_consensus.cc:515] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "72c5715b6fcb400ca248c0a4801fd88f" member_type: VOTER last_known_addr { host: "127.15.239.193" port: 45987 } }
I20260812 06:18:50.765156 16626 leader_election.cc:304] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f [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: 72c5715b6fcb400ca248c0a4801fd88f; no voters: 
I20260812 06:18:50.765408 16626 leader_election.cc:290] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:50.765527 16631 raft_consensus.cc:2804] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:50.765774 16631 raft_consensus.cc:697] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f [term 1 LEADER]: Becoming Leader. State: Replica: 72c5715b6fcb400ca248c0a4801fd88f, State: Running, Role: LEADER
I20260812 06:18:50.765801 16626 ts_tablet_manager.cc:1434] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:18:50.766038 16605 heartbeater.cc:499] Master 127.15.239.254:45199 was elected leader, sending a full tablet report...
I20260812 06:18:50.766193 16631 consensus_queue.cc:237] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f [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: "72c5715b6fcb400ca248c0a4801fd88f" member_type: VOTER last_known_addr { host: "127.15.239.193" port: 45987 } }
I20260812 06:18:50.769620 16379 catalog_manager.cc:5719] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f reported cstate change: term changed from 0 to 1, leader changed from <none> to 72c5715b6fcb400ca248c0a4801fd88f (127.15.239.193). New cstate: current_term: 1 leader_uuid: "72c5715b6fcb400ca248c0a4801fd88f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "72c5715b6fcb400ca248c0a4801fd88f" member_type: VOTER last_known_addr { host: "127.15.239.193" port: 45987 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:50.835014 16319 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.014s	sys 0.012s
I20260812 06:18:50.967794 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushMRSOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=15.086190
I20260812 06:18:51.129828 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushMRSOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.162s	user 0.133s	sys 0.023s Metrics: {"bytes_written":12061348,"cfile_init":1,"compiler_manager_pool.queue_time_us":202,"delete_count":0,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":825,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36120,"lbm_writes_lt_1ms":661,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":394112,"thread_start_us":111,"threads_started":1,"update_count":1470}
I20260812 06:18:51.131454 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling LogGCOp(9fdbcdbac35145bc9517fdb8ecd1960e): free 20743880 bytes of WAL
I20260812 06:18:51.131876 16505 log_reader.cc:385] T 9fdbcdbac35145bc9517fdb8ecd1960e: removed 2 log segments from log reader
I20260812 06:18:51.131958 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000001 (ops 1-6)
I20260812 06:18:51.132028 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000002 (ops 7-11)
I20260812 06:18:51.138104 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: LogGCOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:51.138564 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:51.167764 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.029s	user 0.005s	sys 0.009s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":6129,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:18:51.168303 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:51.182446 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5504,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.183037 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling UndoDeltaBlockGCOp(9fdbcdbac35145bc9517fdb8ecd1960e): 12719216 bytes on disk
I20260812 06:18:51.183622 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: UndoDeltaBlockGCOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:18:51.184154 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:51.356549 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.172s	user 0.114s	sys 0.055s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364565,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":643,"lbm_read_time_us":10986,"lbm_reads_lt_1ms":559,"lbm_write_time_us":33296,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":319,"threads_started":5,"update_count":2450}
I20260812 06:18:51.357095 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=10.126437
I20260812 06:18:51.409266 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.052s	user 0.022s	sys 0.013s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15440,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:51.409981 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:51.424749 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5493,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.425232 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:51.564586 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.139s	user 0.105s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1887,"lbm_read_time_us":8743,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28095,"lbm_writes_lt_1ms":443,"mutex_wait_us":382,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2000}
I20260812 06:18:51.565435 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=10.126437
I20260812 06:18:51.601431 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.036s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15730,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:51.601955 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:51.614005 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4546,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.614733 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:51.763098 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.148s	user 0.123s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":298,"lbm_read_time_us":11529,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29416,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:51.763690 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=10.126437
I20260812 06:18:51.821973 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.058s	user 0.020s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15683,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:51.822680 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:51.833866 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4354,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.834378 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:51.986855 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.152s	user 0.096s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":491,"lbm_read_time_us":11288,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26387,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:51.987411 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=10.126437
I20260812 06:18:52.037521 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.050s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18105,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:52.038069 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:52.050024 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4235,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.050791 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:52.177248 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.126s	user 0.105s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":378,"lbm_read_time_us":9931,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25031,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2000}
I20260812 06:18:52.177944 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=10.126437
I20260812 06:18:52.223304 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.045s	user 0.029s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":20847,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:52.223882 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:52.236621 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4953,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.237090 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:52.367966 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.131s	user 0.107s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":252,"lbm_read_time_us":8389,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29054,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2000}
I20260812 06:18:52.368805 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=10.126437
I20260812 06:18:52.419997 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.051s	user 0.017s	sys 0.033s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":21957,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:52.420544 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:52.434475 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5243,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.435053 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushMRSOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:52.471339 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushMRSOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.035s	user 0.028s	sys 0.005s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":264,"dirs.run_wall_time_us":1435,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2133,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:52.472146 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling LogGCOp(9fdbcdbac35145bc9517fdb8ecd1960e): free 112239269 bytes of WAL
I20260812 06:18:52.472399 16505 log_reader.cc:385] T 9fdbcdbac35145bc9517fdb8ecd1960e: removed 11 log segments from log reader
I20260812 06:18:52.472445 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000003 (ops 12-16)
I20260812 06:18:52.472498 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000004 (ops 17-21)
I20260812 06:18:52.472543 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000005 (ops 22-26)
I20260812 06:18:52.472606 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000006 (ops 27-31)
I20260812 06:18:52.472636 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000007 (ops 32-36)
I20260812 06:18:52.472675 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000008 (ops 37-40)
I20260812 06:18:52.472725 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000009 (ops 41-45)
I20260812 06:18:52.472769 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000010 (ops 46-50)
I20260812 06:18:52.472808 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000011 (ops 51-55)
I20260812 06:18:52.472847 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000012 (ops 56-60)
I20260812 06:18:52.472888 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000013 (ops 61-65)
I20260812 06:18:52.497588 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: LogGCOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:52.498049 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:52.512957 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.015s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4225735,"delete_count":0,"lbm_write_time_us":4569,"lbm_writes_lt_1ms":106,"mutex_wait_us":641,"reinsert_count":0,"update_count":515}
I20260812 06:18:52.513494 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:52.528512 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3979583,"delete_count":0,"lbm_write_time_us":5712,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:18:52.529098 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling UndoDeltaBlockGCOp(9fdbcdbac35145bc9517fdb8ecd1960e): 448 bytes on disk
I20260812 06:18:52.529783 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: UndoDeltaBlockGCOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4}
I20260812 06:18:52.530328 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:52.744011 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.213s	user 0.138s	sys 0.075s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877342,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1095,"lbm_read_time_us":16231,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36498,"lbm_writes_lt_1ms":643,"mutex_wait_us":628,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15360,"thread_start_us":105,"threads_started":1,"update_count":3000}
I20260812 06:18:52.745038 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=14.095187
I20260812 06:18:52.814721 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.069s	user 0.038s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27536,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:52.815220 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:52.826730 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4174,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.827555 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:53.010138 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.182s	user 0.117s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":671,"lbm_read_time_us":13971,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31386,"lbm_writes_lt_1ms":543,"mutex_wait_us":87,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:18:53.010854 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=14.095187
I20260812 06:18:53.069479 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.058s	user 0.012s	sys 0.043s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22190,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:53.070159 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:53.081923 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4486,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.082441 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:53.263266 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.181s	user 0.137s	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":216,"lbm_read_time_us":14745,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32720,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:18:53.264051 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=11.118625
I20260812 06:18:53.298107 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.034s	user 0.018s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14972,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:53.299104 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:53.323520 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.024s	user 0.007s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5983,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:53.324139 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:53.478375 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.154s	user 0.118s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":150,"lbm_read_time_us":9958,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27361,"lbm_writes_lt_1ms":443,"mutex_wait_us":57,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":2000}
I20260812 06:18:53.479184 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=10.126437
I20260812 06:18:53.525305 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.046s	user 0.027s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":20913,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:18:53.525872 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:53.541301 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.015s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5447,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.541882 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:53.670589 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.128s	user 0.103s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":930,"lbm_read_time_us":9196,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24589,"lbm_writes_lt_1ms":443,"mutex_wait_us":305,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2000}
I20260812 06:18:53.671273 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=10.126437
I20260812 06:18:53.708694 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.037s	user 0.028s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16264,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:53.709236 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:53.721124 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4175,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.721650 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:53.859624 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.138s	user 0.117s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1280,"lbm_read_time_us":9342,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27318,"lbm_writes_lt_1ms":443,"mutex_wait_us":407,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2000}
I20260812 06:18:53.864811 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=10.126437
I20260812 06:18:53.912189 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.047s	user 0.030s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17542,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:53.912806 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:53.924379 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4589,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.924981 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushMRSOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:53.970564 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushMRSOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.045s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":36,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":1570,"drs_written":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1992,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:53.971388 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling LogGCOp(9fdbcdbac35145bc9517fdb8ecd1960e): free 112239375 bytes of WAL
I20260812 06:18:53.971639 16505 log_reader.cc:385] T 9fdbcdbac35145bc9517fdb8ecd1960e: removed 11 log segments from log reader
I20260812 06:18:53.971710 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000014 (ops 66-70)
I20260812 06:18:53.971762 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000015 (ops 71-75)
I20260812 06:18:53.971820 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000016 (ops 76-80)
I20260812 06:18:53.971864 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000017 (ops 81-84)
I20260812 06:18:53.971906 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000018 (ops 85-89)
I20260812 06:18:53.971948 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000019 (ops 90-94)
I20260812 06:18:53.971985 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000020 (ops 95-99)
I20260812 06:18:53.972025 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000021 (ops 100-104)
I20260812 06:18:53.972066 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000022 (ops 105-109)
I20260812 06:18:53.972105 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000023 (ops 110-114)
I20260812 06:18:53.972146 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000024 (ops 115-119)
I20260812 06:18:53.997849 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: LogGCOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:53.998307 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling UndoDeltaBlockGCOp(9fdbcdbac35145bc9517fdb8ecd1960e): 447 bytes on disk
I20260812 06:18:53.998996 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: UndoDeltaBlockGCOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:18:53.999861 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=3.181125
I20260812 06:18:54.019801 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.020s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4661,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:54.020291 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:54.030575 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3855,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:54.031183 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:54.244776 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.213s	user 0.135s	sys 0.077s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":813,"lbm_read_time_us":14415,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36538,"lbm_writes_lt_1ms":643,"mutex_wait_us":720,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":95,"threads_started":1,"update_count":3000}
I20260812 06:18:54.246127 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=14.095187
I20260812 06:18:54.305974 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.059s	user 0.022s	sys 0.033s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":30336,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:54.306586 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:54.324005 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.017s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6181,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.324455 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:54.513703 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.189s	user 0.119s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":153,"lbm_read_time_us":13382,"lbm_reads_lt_1ms":568,"lbm_write_time_us":33722,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:18:54.514467 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=14.095187
I20260812 06:18:54.575958 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.061s	user 0.027s	sys 0.031s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21715,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:54.576691 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:54.595084 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.018s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6977,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.595669 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:54.777591 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.182s	user 0.117s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":858,"lbm_read_time_us":14277,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33285,"lbm_writes_lt_1ms":543,"mutex_wait_us":388,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:54.778251 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=10.126437
I20260812 06:18:54.816023 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.038s	user 0.028s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16141,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.816636 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:54.843752 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.027s	user 0.018s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6008,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.844401 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:55.001586 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.157s	user 0.100s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":229,"lbm_read_time_us":13937,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24714,"lbm_writes_lt_1ms":443,"mutex_wait_us":74,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:55.002353 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=10.126437
I20260812 06:18:55.045082 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.042s	user 0.014s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19106,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:55.045687 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:55.058051 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4707,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.058753 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:55.195827 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.137s	user 0.107s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":357,"lbm_read_time_us":9937,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27323,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:55.196640 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=10.126437
I20260812 06:18:55.245059 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.048s	user 0.026s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21089,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:55.245595 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:55.260363 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5357,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.260913 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:55.403090 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.142s	user 0.102s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":166,"lbm_read_time_us":10969,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28731,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":26496,"update_count":2000}
I20260812 06:18:55.403787 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=10.126437
I20260812 06:18:55.457233 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.053s	user 0.019s	sys 0.031s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":20157,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:55.457899 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:55.469033 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4178,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.469748 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushMRSOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:55.507892 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushMRSOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.038s	user 0.022s	sys 0.003s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1486,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2100,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:55.508678 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling LogGCOp(9fdbcdbac35145bc9517fdb8ecd1960e): free 120553596 bytes of WAL
I20260812 06:18:55.508921 16505 log_reader.cc:385] T 9fdbcdbac35145bc9517fdb8ecd1960e: removed 12 log segments from log reader
I20260812 06:18:55.508968 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000025 (ops 120-124)
I20260812 06:18:55.508998 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000026 (ops 125-129)
I20260812 06:18:55.509063 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000027 (ops 130-134)
I20260812 06:18:55.509105 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000028 (ops 135-139)
I20260812 06:18:55.509148 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000029 (ops 140-144)
I20260812 06:18:55.509188 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000030 (ops 145-149)
I20260812 06:18:55.509229 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000031 (ops 150-154)
I20260812 06:18:55.509268 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000032 (ops 155-158)
I20260812 06:18:55.509308 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000033 (ops 159-163)
I20260812 06:18:55.509348 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000034 (ops 164-168)
I20260812 06:18:55.509392 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000035 (ops 169-172)
I20260812 06:18:55.509431 16505 log.cc:1079] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/9fdbcdbac35145bc9517fdb8ecd1960e/wal-000000036 (ops 173-177)
I20260812 06:18:55.536214 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: LogGCOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:55.536752 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling UndoDeltaBlockGCOp(9fdbcdbac35145bc9517fdb8ecd1960e): 447 bytes on disk
I20260812 06:18:55.537194 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: UndoDeltaBlockGCOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:55.537849 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=3.181125
I20260812 06:18:55.552551 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.015s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4348807,"delete_count":0,"lbm_write_time_us":4490,"lbm_writes_lt_1ms":109,"reinsert_count":0,"update_count":530}
I20260812 06:18:55.552989 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:55.562943 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":3820,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:18:55.563439 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:55.774446 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.211s	user 0.129s	sys 0.080s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877336,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":613,"lbm_read_time_us":15185,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34576,"lbm_writes_lt_1ms":643,"mutex_wait_us":1584,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15616,"thread_start_us":122,"threads_started":1,"update_count":3000}
I20260812 06:18:55.775367 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=14.095187
I20260812 06:18:55.827832 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.052s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20549,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:55.828402 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:55.839715 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4306,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.840327 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:56.021878 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.181s	user 0.125s	sys 0.056s 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":1166,"lbm_read_time_us":12891,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31119,"lbm_writes_lt_1ms":543,"mutex_wait_us":344,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:18:56.022588 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=14.095187
I20260812 06:18:56.068315 16319 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.233s	user 1.952s	sys 0.166s
I20260812 06:18:56.080416 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.058s	user 0.032s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22077,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:56.080991 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=2.188937
I20260812 06:18:56.091318 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: FlushDeltaMemStoresOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4322,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":500}
I20260812 06:18:56.091794 16606 maintenance_manager.cc:419] P 72c5715b6fcb400ca248c0a4801fd88f: Scheduling MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e): perf score=1.000000
I20260812 06:18:56.148726 16319 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.080s	user 0.002s	sys 0.000s
I20260812 06:18:56.149432 16319 tablet_server.cc:179] TabletServer@127.15.239.193:0 shutting down...
I20260812 06:18:56.227151 16505 maintenance_manager.cc:643] P 72c5715b6fcb400ca248c0a4801fd88f: MajorDeltaCompactionOp(9fdbcdbac35145bc9517fdb8ecd1960e) complete. Timing: real 0.135s	user 0.105s	sys 0.029s Metrics: {"cfile_cache_hit":263,"cfile_cache_hit_bytes":10750249,"cfile_cache_miss":269,"cfile_cache_miss_bytes":14024439,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1568,"lbm_read_time_us":7652,"lbm_reads_lt_1ms":301,"lbm_write_time_us":27059,"lbm_writes_lt_1ms":543,"mutex_wait_us":386,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2500}
I20260812 06:18:56.227866 16319 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:56.228288 16319 tablet_replica.cc:333] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f: stopping tablet replica
I20260812 06:18:56.228559 16319 raft_consensus.cc:2243] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:56.228827 16319 raft_consensus.cc:2272] T 9fdbcdbac35145bc9517fdb8ecd1960e P 72c5715b6fcb400ca248c0a4801fd88f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:56.244186 16319 tablet_server.cc:196] TabletServer@127.15.239.193:0 shutdown complete.
I20260812 06:18:56.273689 16319 master.cc:562] Master@127.15.239.254:45199 shutting down...
I20260812 06:18:56.277343 16319 raft_consensus.cc:2243] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:56.277559 16319 raft_consensus.cc:2272] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:56.277663 16319 tablet_replica.cc:333] T 00000000000000000000000000000000 P efdc969006de4b2ebdb2b27f36ec22cd: stopping tablet replica
I20260812 06:18:56.290154 16319 master.cc:584] Master@127.15.239.254:45199 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5845 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:56.406627 16319 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.15.239.254:32883
I20260812 06:18:56.407162 16319 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:56.409325 16665 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:56.409337 16663 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:18:56.409440 16319 server_base.cc:1061] running on GCE node
W20260812 06:18:56.409518 16668 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:56.409746 16319 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:56.409796 16319 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:56.409814 16319 hybrid_clock.cc:648] HybridClock initialized: now 1786515536409815 us; error 0 us; skew 500 ppm
I20260812 06:18:56.410985 16319 webserver.cc:533] Webserver started at http://127.15.239.254:44541/ using document root <none> and password file <none>
I20260812 06:18:56.411199 16319 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:56.411267 16319 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:56.411363 16319 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:56.411835 16319 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/master-0-root/instance:
uuid: "ec607c325a004348a76a0a18cd72f11b"
format_stamp: "Formatted at 2026-08-12 06:18:56 on dist-test-slave-twwt"
I20260812 06:18:56.413476 16319 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:56.414458 16677 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:56.414746 16319 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:56.414856 16319 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/master-0-root
uuid: "ec607c325a004348a76a0a18cd72f11b"
format_stamp: "Formatted at 2026-08-12 06:18:56 on dist-test-slave-twwt"
I20260812 06:18:56.414963 16319 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:56.462419 16319 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:56.463003 16319 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:56.467547 16319 rpc_server.cc:307] RPC server started. Bound to: 127.15.239.254:32883
I20260812 06:18:56.468251 16772 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.239.254:32883 every 8 connection(s)
I20260812 06:18:56.468923 16773 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:56.471084 16773 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b: Bootstrap starting.
I20260812 06:18:56.471961 16773 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:56.473090 16773 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b: No bootstrap required, opened a new log
I20260812 06:18:56.473564 16773 raft_consensus.cc:359] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec607c325a004348a76a0a18cd72f11b" member_type: VOTER }
I20260812 06:18:56.473663 16773 raft_consensus.cc:385] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:56.473731 16773 raft_consensus.cc:740] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ec607c325a004348a76a0a18cd72f11b, State: Initialized, Role: FOLLOWER
I20260812 06:18:56.473935 16773 consensus_queue.cc:260] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [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: "ec607c325a004348a76a0a18cd72f11b" member_type: VOTER }
I20260812 06:18:56.474016 16773 raft_consensus.cc:399] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:56.474089 16773 raft_consensus.cc:493] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:56.474154 16773 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:56.475003 16773 raft_consensus.cc:515] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec607c325a004348a76a0a18cd72f11b" member_type: VOTER }
I20260812 06:18:56.475174 16773 leader_election.cc:304] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [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: ec607c325a004348a76a0a18cd72f11b; no voters: 
I20260812 06:18:56.475412 16773 leader_election.cc:290] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:56.475541 16778 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:56.475791 16778 raft_consensus.cc:697] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [term 1 LEADER]: Becoming Leader. State: Replica: ec607c325a004348a76a0a18cd72f11b, State: Running, Role: LEADER
I20260812 06:18:56.475980 16773 sys_catalog.cc:565] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:56.475941 16778 consensus_queue.cc:237] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [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: "ec607c325a004348a76a0a18cd72f11b" member_type: VOTER }
I20260812 06:18:56.476485 16779 sys_catalog.cc:455] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ec607c325a004348a76a0a18cd72f11b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec607c325a004348a76a0a18cd72f11b" member_type: VOTER } }
I20260812 06:18:56.476509 16781 sys_catalog.cc:455] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [sys.catalog]: SysCatalogTable state changed. Reason: New leader ec607c325a004348a76a0a18cd72f11b. Latest consensus state: current_term: 1 leader_uuid: "ec607c325a004348a76a0a18cd72f11b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec607c325a004348a76a0a18cd72f11b" member_type: VOTER } }
I20260812 06:18:56.476676 16781 sys_catalog.cc:458] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:56.476660 16779 sys_catalog.cc:458] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:56.477131 16788 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:56.478071 16788 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:56.478255 16319 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:56.480156 16788 catalog_manager.cc:1383] Generated new cluster ID: 911f3073a6914b8c8757d32748e1ba4b
I20260812 06:18:56.480212 16788 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:56.495141 16788 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:56.495801 16788 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:56.504073 16788 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b: Generated new TSK 0
I20260812 06:18:56.504294 16788 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:56.511075 16319 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:56.513119 16806 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:56.513135 16807 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:56.513141 16809 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:56.513284 16319 server_base.cc:1061] running on GCE node
I20260812 06:18:56.513616 16319 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:56.513667 16319 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:56.513690 16319 hybrid_clock.cc:648] HybridClock initialized: now 1786515536513691 us; error 0 us; skew 500 ppm
I20260812 06:18:56.514658 16319 webserver.cc:533] Webserver started at http://127.15.239.193:41553/ using document root <none> and password file <none>
I20260812 06:18:56.514863 16319 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:56.514938 16319 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:56.515025 16319 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:56.515434 16319 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/instance:
uuid: "b03b303c9b204874b7f4703f4b4ce92f"
format_stamp: "Formatted at 2026-08-12 06:18:56 on dist-test-slave-twwt"
I20260812 06:18:56.517055 16319 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:56.518036 16817 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:56.518340 16319 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:56.518441 16319 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root
uuid: "b03b303c9b204874b7f4703f4b4ce92f"
format_stamp: "Formatted at 2026-08-12 06:18:56 on dist-test-slave-twwt"
I20260812 06:18:56.518546 16319 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:56.536166 16319 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:56.536605 16319 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:56.536948 16319 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:56.537462 16319 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:56.537528 16319 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:56.537587 16319 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:56.537639 16319 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:56.542203 16319 rpc_server.cc:307] RPC server started. Bound to: 127.15.239.193:33981
I20260812 06:18:56.542721 16925 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.15.239.193:33981 every 8 connection(s)
I20260812 06:18:56.553251 16927 heartbeater.cc:344] Connected to a master server at 127.15.239.254:32883
I20260812 06:18:56.553376 16927 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:56.553617 16927 heartbeater.cc:507] Master 127.15.239.254:32883 requested a full tablet report, sending...
I20260812 06:18:56.554289 16705 ts_manager.cc:194] Registered new tserver with Master: b03b303c9b204874b7f4703f4b4ce92f (127.15.239.193:33981)
I20260812 06:18:56.555068 16319 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012154769s
I20260812 06:18:56.555158 16705 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33278
I20260812 06:18:56.562525 16705 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33288:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:56.573158 16864 tablet_service.cc:1511] Processing CreateTablet for tablet 8c8b67b8e3204544ac916c2a4be8dc49 (DEFAULT_TABLE table=heavy-update-compaction-test [id=f8d304725e024c278d29779bb24d5fd0]), partition=
I20260812 06:18:56.573443 16864 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8c8b67b8e3204544ac916c2a4be8dc49. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:56.575714 16940 tablet_bootstrap.cc:492] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Bootstrap starting.
I20260812 06:18:56.576682 16940 tablet_bootstrap.cc:654] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:56.578128 16940 tablet_bootstrap.cc:492] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: No bootstrap required, opened a new log
I20260812 06:18:56.578236 16940 ts_tablet_manager.cc:1403] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:56.578995 16940 raft_consensus.cc:359] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b03b303c9b204874b7f4703f4b4ce92f" member_type: VOTER last_known_addr { host: "127.15.239.193" port: 33981 } }
I20260812 06:18:56.579095 16940 raft_consensus.cc:385] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:56.579118 16940 raft_consensus.cc:740] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b03b303c9b204874b7f4703f4b4ce92f, State: Initialized, Role: FOLLOWER
I20260812 06:18:56.579303 16940 consensus_queue.cc:260] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f [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: "b03b303c9b204874b7f4703f4b4ce92f" member_type: VOTER last_known_addr { host: "127.15.239.193" port: 33981 } }
I20260812 06:18:56.579398 16940 raft_consensus.cc:399] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:56.579473 16940 raft_consensus.cc:493] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:56.579532 16940 raft_consensus.cc:3060] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:56.580703 16940 raft_consensus.cc:515] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b03b303c9b204874b7f4703f4b4ce92f" member_type: VOTER last_known_addr { host: "127.15.239.193" port: 33981 } }
I20260812 06:18:56.580919 16940 leader_election.cc:304] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f [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: b03b303c9b204874b7f4703f4b4ce92f; no voters: 
I20260812 06:18:56.581172 16940 leader_election.cc:290] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:56.581326 16946 raft_consensus.cc:2804] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:56.581535 16927 heartbeater.cc:499] Master 127.15.239.254:32883 was elected leader, sending a full tablet report...
I20260812 06:18:56.581571 16946 raft_consensus.cc:697] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f [term 1 LEADER]: Becoming Leader. State: Replica: b03b303c9b204874b7f4703f4b4ce92f, State: Running, Role: LEADER
I20260812 06:18:56.581530 16940 ts_tablet_manager.cc:1434] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:18:56.581769 16946 consensus_queue.cc:237] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f [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: "b03b303c9b204874b7f4703f4b4ce92f" member_type: VOTER last_known_addr { host: "127.15.239.193" port: 33981 } }
I20260812 06:18:56.583297 16705 catalog_manager.cc:5719] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f reported cstate change: term changed from 0 to 1, leader changed from <none> to b03b303c9b204874b7f4703f4b4ce92f (127.15.239.193). New cstate: current_term: 1 leader_uuid: "b03b303c9b204874b7f4703f4b4ce92f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b03b303c9b204874b7f4703f4b4ce92f" member_type: VOTER last_known_addr { host: "127.15.239.193" port: 33981 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:56.644183 16319 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.013s	sys 0.010s
I20260812 06:18:56.793386 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushMRSOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=19.054940
I20260812 06:18:56.943879 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushMRSOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.150s	user 0.112s	sys 0.035s Metrics: {"bytes_written":12307489,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":929,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37267,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:56.944545 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling LogGCOp(8c8b67b8e3204544ac916c2a4be8dc49): free 20743880 bytes of WAL
I20260812 06:18:56.944794 16831 log_reader.cc:385] T 8c8b67b8e3204544ac916c2a4be8dc49: removed 2 log segments from log reader
I20260812 06:18:56.944842 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000001 (ops 1-6)
I20260812 06:18:56.944901 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000002 (ops 7-11)
I20260812 06:18:56.949227 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: LogGCOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:56.949656 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:18:56.969563 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.020s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6418,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.970207 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:18:57.148751 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.178s	user 0.096s	sys 0.070s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":627,"lbm_read_time_us":10584,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26814,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":328,"threads_started":5,"update_count":2000}
I20260812 06:18:57.149326 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=14.095187
I20260812 06:18:57.201746 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.052s	user 0.032s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19471,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.202243 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling UndoDeltaBlockGCOp(8c8b67b8e3204544ac916c2a4be8dc49): 16411395 bytes on disk
I20260812 06:18:57.202755 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: UndoDeltaBlockGCOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:18:57.203213 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:18:57.214793 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.011s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4154,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.215313 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:18:57.375748 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.160s	user 0.105s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":192,"lbm_read_time_us":12529,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29422,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:18:57.376504 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=11.118625
I20260812 06:18:57.431712 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.055s	user 0.027s	sys 0.023s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":22279,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:57.432206 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:18:57.443836 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4546,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.444288 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:18:57.454232 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3753,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:57.454846 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:18:57.636404 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.181s	user 0.127s	sys 0.042s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1615,"lbm_read_time_us":11397,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34662,"lbm_writes_lt_1ms":543,"mutex_wait_us":397,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:18:57.637090 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=14.095187
I20260812 06:18:57.695771 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.059s	user 0.038s	sys 0.015s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":24686,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.696257 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:18:57.708609 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4190,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.709259 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:18:57.903891 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.194s	user 0.115s	sys 0.079s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1214,"lbm_read_time_us":13698,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28771,"lbm_writes_lt_1ms":543,"mutex_wait_us":422,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21248,"update_count":2500}
I20260812 06:18:57.904584 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=14.095187
I20260812 06:18:57.964929 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.060s	user 0.032s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26559,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.965647 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:18:58.117337 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.151s	user 0.119s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":923,"lbm_read_time_us":10909,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24254,"lbm_writes_lt_1ms":443,"mutex_wait_us":299,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2000}
I20260812 06:18:58.118017 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=14.095187
I20260812 06:18:58.175974 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.058s	user 0.042s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25376,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:58.176535 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:18:58.189491 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4499,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.190222 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushMRSOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:18:58.232004 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushMRSOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.042s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":145,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":1552,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2211,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:58.232667 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling LogGCOp(8c8b67b8e3204544ac916c2a4be8dc49): free 111786258 bytes of WAL
I20260812 06:18:58.232928 16831 log_reader.cc:385] T 8c8b67b8e3204544ac916c2a4be8dc49: removed 11 log segments from log reader
I20260812 06:18:58.232972 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000003 (ops 12-16)
I20260812 06:18:58.233024 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000004 (ops 17-20)
I20260812 06:18:58.233071 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000005 (ops 21-25)
I20260812 06:18:58.233115 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000006 (ops 26-30)
I20260812 06:18:58.233155 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000007 (ops 31-35)
I20260812 06:18:58.233215 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000008 (ops 36-40)
I20260812 06:18:58.233258 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000009 (ops 41-45)
I20260812 06:18:58.233301 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000010 (ops 46-50)
I20260812 06:18:58.233340 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000011 (ops 51-55)
I20260812 06:18:58.233381 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000012 (ops 56-60)
I20260812 06:18:58.233419 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000013 (ops 61-64)
I20260812 06:18:58.259141 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: LogGCOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:58.259524 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling UndoDeltaBlockGCOp(8c8b67b8e3204544ac916c2a4be8dc49): 449 bytes on disk
I20260812 06:18:58.259933 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: UndoDeltaBlockGCOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:18:58.260382 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=3.181125
I20260812 06:18:58.284946 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.024s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6486,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:58.285447 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:18:58.295467 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3750,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:58.295931 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:18:58.545282 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.249s	user 0.152s	sys 0.090s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979738,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":235,"lbm_read_time_us":17464,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40411,"lbm_writes_lt_1ms":743,"mutex_wait_us":29,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":103424,"thread_start_us":90,"threads_started":1,"update_count":3500}
I20260812 06:18:58.545910 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=18.063937
I20260812 06:18:58.606721 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.061s	user 0.044s	sys 0.015s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26923,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:58.607295 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:18:58.808430 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.201s	user 0.151s	sys 0.047s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774572,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":417,"lbm_read_time_us":14054,"lbm_reads_lt_1ms":563,"lbm_write_time_us":34401,"lbm_writes_lt_1ms":543,"mutex_wait_us":105,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2500}
I20260812 06:18:58.809281 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=18.063937
I20260812 06:18:58.890066 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.081s	user 0.037s	sys 0.039s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":35554,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:18:58.890909 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:18:58.908209 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6582,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.908690 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:18:59.123493 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.215s	user 0.149s	sys 0.065s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":394,"lbm_read_time_us":15414,"lbm_reads_lt_1ms":668,"lbm_write_time_us":34770,"lbm_writes_lt_1ms":643,"mutex_wait_us":36,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19072,"update_count":3000}
I20260812 06:18:59.124056 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=18.063937
I20260812 06:18:59.189110 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.065s	user 0.037s	sys 0.016s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25026,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:59.189720 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:18:59.201664 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4499,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.202454 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:18:59.406499 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.204s	user 0.116s	sys 0.088s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1144,"lbm_read_time_us":13523,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34002,"lbm_writes_lt_1ms":643,"mutex_wait_us":377,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18816,"update_count":3000}
I20260812 06:18:59.407483 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=14.095187
I20260812 06:18:59.455648 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.048s	user 0.036s	sys 0.011s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":21152,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:59.456416 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:18:59.473889 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6411,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.474413 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:18:59.662817 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.188s	user 0.119s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":621,"lbm_read_time_us":13872,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32425,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2500}
I20260812 06:18:59.663702 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=14.095187
I20260812 06:18:59.726387 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.062s	user 0.017s	sys 0.042s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22355,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:59.727064 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:18:59.746047 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.019s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7142,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.746848 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushMRSOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:18:59.783489 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushMRSOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.036s	user 0.027s	sys 0.005s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":266,"dirs.run_wall_time_us":1428,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1686,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:59.784291 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling LogGCOp(8c8b67b8e3204544ac916c2a4be8dc49): free 121006434 bytes of WAL
I20260812 06:18:59.784600 16831 log_reader.cc:385] T 8c8b67b8e3204544ac916c2a4be8dc49: removed 12 log segments from log reader
I20260812 06:18:59.784665 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000014 (ops 65-69)
I20260812 06:18:59.784705 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000015 (ops 70-74)
I20260812 06:18:59.784739 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000016 (ops 75-79)
I20260812 06:18:59.784767 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000017 (ops 80-84)
I20260812 06:18:59.784801 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000018 (ops 85-89)
I20260812 06:18:59.784827 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000019 (ops 90-94)
I20260812 06:18:59.784857 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000020 (ops 95-98)
I20260812 06:18:59.784883 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000021 (ops 99-103)
I20260812 06:18:59.784912 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000022 (ops 104-108)
I20260812 06:18:59.784955 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000023 (ops 109-113)
I20260812 06:18:59.784983 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000024 (ops 114-118)
I20260812 06:18:59.785005 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000025 (ops 119-123)
I20260812 06:18:59.815829 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: LogGCOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.031s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:18:59.816425 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:18:59.840999 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.024s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4864,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.841574 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:18:59.852547 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4095,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.853214 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:19:00.103116 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.250s	user 0.179s	sys 0.064s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979752,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":49,"lbm_read_time_us":16469,"lbm_reads_lt_1ms":774,"lbm_write_time_us":46157,"lbm_writes_lt_1ms":743,"mutex_wait_us":47,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11264,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:19:00.103950 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=15.087375
I20260812 06:19:00.172484 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.068s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16820139,"delete_count":0,"lbm_write_time_us":36957,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:19:00.172999 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling UndoDeltaBlockGCOp(8c8b67b8e3204544ac916c2a4be8dc49): 463 bytes on disk
I20260812 06:19:00.173451 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: UndoDeltaBlockGCOp(8c8b67b8e3204544ac916c2a4be8dc49) 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:19:00.173974 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=6.157687
I20260812 06:19:00.195284 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.021s	user 0.017s	sys 0.003s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":9208,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:00.195777 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:19:00.384586 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.189s	user 0.145s	sys 0.043s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":661,"lbm_read_time_us":13903,"lbm_reads_lt_1ms":672,"lbm_write_time_us":39535,"lbm_writes_lt_1ms":643,"mutex_wait_us":413,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":43520,"update_count":3000}
I20260812 06:19:00.385267 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=14.095187
I20260812 06:19:00.446756 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.061s	user 0.036s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26195,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:00.447374 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:19:00.461282 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5357,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.461815 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:19:00.676440 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.214s	user 0.150s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1233,"lbm_read_time_us":14195,"lbm_reads_lt_1ms":572,"lbm_write_time_us":44002,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9436288,"update_count":2500}
I20260812 06:19:00.677291 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=14.095187
I20260812 06:19:00.759111 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.082s	user 0.034s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":29468,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:00.759737 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:19:00.771637 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4531,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.772230 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:19:00.979228 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.207s	user 0.148s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":704,"lbm_read_time_us":15480,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36751,"lbm_writes_lt_1ms":543,"mutex_wait_us":318,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2500}
I20260812 06:19:00.980203 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=14.095187
I20260812 06:19:01.041582 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.061s	user 0.023s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27852,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:01.042272 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:19:01.054447 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4846,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.055065 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:19:01.237085 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.182s	user 0.114s	sys 0.066s 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":171,"lbm_read_time_us":13287,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33579,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2500}
I20260812 06:19:01.239003 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=14.095187
I20260812 06:19:01.303182 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.064s	user 0.024s	sys 0.033s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21138,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:01.303784 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:19:01.315001 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4348,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.315558 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushMRSOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:19:01.359524 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushMRSOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.044s	user 0.025s	sys 0.005s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":315,"dirs.run_wall_time_us":1624,"drs_written":1,"lbm_read_time_us":84,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2147,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:01.360245 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling LogGCOp(8c8b67b8e3204544ac916c2a4be8dc49): free 115943400 bytes of WAL
I20260812 06:19:01.360500 16831 log_reader.cc:385] T 8c8b67b8e3204544ac916c2a4be8dc49: removed 11 log segments from log reader
I20260812 06:19:01.360546 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000026 (ops 124-128)
I20260812 06:19:01.360577 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000027 (ops 129-133)
I20260812 06:19:01.360643 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000028 (ops 134-138)
I20260812 06:19:01.360697 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000029 (ops 139-143)
I20260812 06:19:01.360745 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000030 (ops 144-148)
I20260812 06:19:01.360783 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000031 (ops 149-153)
I20260812 06:19:01.360823 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000032 (ops 154-158)
I20260812 06:19:01.360865 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000033 (ops 159-163)
I20260812 06:19:01.360903 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000034 (ops 164-168)
I20260812 06:19:01.360932 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000035 (ops 169-173)
I20260812 06:19:01.360965 16831 log.cc:1079] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: Deleting log segment in path: /tmp/dist-test-taskgGI_FV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515530535192-16319-0/minicluster-data/ts-0-root/wals/8c8b67b8e3204544ac916c2a4be8dc49/wal-000000036 (ops 174-178)
I20260812 06:19:01.388231 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: LogGCOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:01.388710 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling UndoDeltaBlockGCOp(8c8b67b8e3204544ac916c2a4be8dc49): 447 bytes on disk
I20260812 06:19:01.389161 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: UndoDeltaBlockGCOp(8c8b67b8e3204544ac916c2a4be8dc49) 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:19:01.389710 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=3.181125
I20260812 06:19:01.414234 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.024s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7267,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:01.414819 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:19:01.425048 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3796,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:01.425554 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:19:01.680706 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.255s	user 0.160s	sys 0.091s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":643,"lbm_read_time_us":18283,"lbm_reads_lt_1ms":774,"lbm_write_time_us":45728,"lbm_writes_lt_1ms":743,"mutex_wait_us":64,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3840,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:19:01.682345 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=15.087375
I20260812 06:19:01.736346 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.053s	user 0.032s	sys 0.020s Metrics: {"bytes_written":16820141,"delete_count":0,"lbm_write_time_us":23788,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:01.736961 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:19:01.760336 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.023s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4514,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:01.760828 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=2.188937
I20260812 06:19:01.772059 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4230,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.772782 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:19:01.894577 16319 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.250s	user 1.943s	sys 0.204s
I20260812 06:19:01.934968 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.162s	user 0.107s	sys 0.055s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877205,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"lbm_read_time_us":12558,"lbm_reads_lt_1ms":669,"lbm_write_time_us":34132,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:01.935532 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=10.126437
I20260812 06:19:01.970515 16319 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.075s	user 0.000s	sys 0.001s
I20260812 06:19:01.971167 16319 tablet_server.cc:179] TabletServer@127.15.239.193:0 shutting down...
I20260812 06:19:01.974144 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: FlushDeltaMemStoresOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.038s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17198,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:01.974856 16928 maintenance_manager.cc:419] P b03b303c9b204874b7f4703f4b4ce92f: Scheduling MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49): perf score=1.000000
I20260812 06:19:02.069756 16831 maintenance_manager.cc:643] P b03b303c9b204874b7f4703f4b4ce92f: MajorDeltaCompactionOp(8c8b67b8e3204544ac916c2a4be8dc49) complete. Timing: real 0.095s	user 0.080s	sys 0.014s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569747,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":500,"lbm_read_time_us":7369,"lbm_reads_lt_1ms":367,"lbm_write_time_us":17853,"lbm_writes_lt_1ms":343,"mutex_wait_us":57,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:19:02.070310 16319 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:02.070664 16319 tablet_replica.cc:333] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f: stopping tablet replica
I20260812 06:19:02.070816 16319 raft_consensus.cc:2243] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:02.071018 16319 raft_consensus.cc:2272] T 8c8b67b8e3204544ac916c2a4be8dc49 P b03b303c9b204874b7f4703f4b4ce92f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:02.076380 16319 tablet_server.cc:196] TabletServer@127.15.239.193:0 shutdown complete.
I20260812 06:19:02.103770 16319 master.cc:562] Master@127.15.239.254:32883 shutting down...
I20260812 06:19:02.106992 16319 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:02.107180 16319 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:02.107232 16319 tablet_replica.cc:333] T 00000000000000000000000000000000 P ec607c325a004348a76a0a18cd72f11b: stopping tablet replica
I20260812 06:19:02.119745 16319 master.cc:584] Master@127.15.239.254:32883 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5827 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11673 ms total)

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