[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:21.139509 27939 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.72.254:35103
I20260812 06:19:21.140522 27939 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:21.141099 27939 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:21.147843 27946 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:21.148011 27939 server_base.cc:1061] running on GCE node
W20260812 06:19:21.147943 27948 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:21.148171 27945 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:21.148628 27939 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:21.148715 27939 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:21.148751 27939 hybrid_clock.cc:648] HybridClock initialized: now 1786515561148742 us; error 0 us; skew 500 ppm
I20260812 06:19:21.150483 27939 webserver.cc:533] Webserver started at http://127.27.72.254:42193/ using document root <none> and password file <none>
I20260812 06:19:21.150957 27939 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:21.151010 27939 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:21.151181 27939 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:21.152779 27939 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/master-0-root/instance:
uuid: "cd8055a526ba4ada9f5541117d6b4f1d"
format_stamp: "Formatted at 2026-08-12 06:19:21 on dist-test-slave-6k22"
I20260812 06:19:21.156075 27939 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:21.157905 27957 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:21.158874 27939 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:21.158967 27939 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/master-0-root
uuid: "cd8055a526ba4ada9f5541117d6b4f1d"
format_stamp: "Formatted at 2026-08-12 06:19:21 on dist-test-slave-6k22"
I20260812 06:19:21.159042 27939 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:21.196158 27939 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:21.196802 27939 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:21.196943 27939 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:21.204519 27939 rpc_server.cc:307] RPC server started. Bound to: 127.27.72.254:35103
I20260812 06:19:21.204532 28027 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.72.254:35103 every 8 connection(s)
I20260812 06:19:21.206856 28028 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:21.212106 28028 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d: Bootstrap starting.
I20260812 06:19:21.214366 28028 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:21.215292 28028 log.cc:826] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:21.216980 28028 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d: No bootstrap required, opened a new log
I20260812 06:19:21.219704 28028 raft_consensus.cc:359] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cd8055a526ba4ada9f5541117d6b4f1d" member_type: VOTER }
I20260812 06:19:21.219857 28028 raft_consensus.cc:385] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:21.219995 28028 raft_consensus.cc:740] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: cd8055a526ba4ada9f5541117d6b4f1d, State: Initialized, Role: FOLLOWER
I20260812 06:19:21.220638 28028 consensus_queue.cc:260] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [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: "cd8055a526ba4ada9f5541117d6b4f1d" member_type: VOTER }
I20260812 06:19:21.220813 28028 raft_consensus.cc:399] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:21.220880 28028 raft_consensus.cc:493] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:21.221019 28028 raft_consensus.cc:3060] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:21.221792 28028 raft_consensus.cc:515] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cd8055a526ba4ada9f5541117d6b4f1d" member_type: VOTER }
I20260812 06:19:21.222219 28028 leader_election.cc:304] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [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: cd8055a526ba4ada9f5541117d6b4f1d; no voters: 
I20260812 06:19:21.222543 28028 leader_election.cc:290] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:21.222656 28033 raft_consensus.cc:2804] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:21.222965 28033 raft_consensus.cc:697] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [term 1 LEADER]: Becoming Leader. State: Replica: cd8055a526ba4ada9f5541117d6b4f1d, State: Running, Role: LEADER
I20260812 06:19:21.223440 28033 consensus_queue.cc:237] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [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: "cd8055a526ba4ada9f5541117d6b4f1d" member_type: VOTER }
I20260812 06:19:21.223528 28028 sys_catalog.cc:565] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:21.225248 28035 sys_catalog.cc:455] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [sys.catalog]: SysCatalogTable state changed. Reason: New leader cd8055a526ba4ada9f5541117d6b4f1d. Latest consensus state: current_term: 1 leader_uuid: "cd8055a526ba4ada9f5541117d6b4f1d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cd8055a526ba4ada9f5541117d6b4f1d" member_type: VOTER } }
I20260812 06:19:21.225293 28034 sys_catalog.cc:455] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "cd8055a526ba4ada9f5541117d6b4f1d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cd8055a526ba4ada9f5541117d6b4f1d" member_type: VOTER } }
I20260812 06:19:21.225368 28035 sys_catalog.cc:458] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:21.225410 28034 sys_catalog.cc:458] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:21.225733 28048 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:21.225992 27939 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:21.228498 28048 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:21.233023 28048 catalog_manager.cc:1383] Generated new cluster ID: bf569aa93e474503bfbb8e1a7f34dd5f
I20260812 06:19:21.233088 28048 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:21.262650 28048 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:21.263751 28048 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:21.270454 28048 catalog_manager.cc:6092] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d: Generated new TSK 0
I20260812 06:19:21.271090 28048 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:21.290938 27939 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:21.294061 28058 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:21.294250 27939 server_base.cc:1061] running on GCE node
W20260812 06:19:21.294116 28061 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:21.294142 28059 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:21.294634 27939 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:21.294678 27939 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:21.294694 27939 hybrid_clock.cc:648] HybridClock initialized: now 1786515561294694 us; error 0 us; skew 500 ppm
I20260812 06:19:21.295691 27939 webserver.cc:533] Webserver started at http://127.27.72.193:39297/ using document root <none> and password file <none>
I20260812 06:19:21.295866 27939 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:21.295925 27939 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:21.296026 27939 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:21.296435 27939 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/instance:
uuid: "ab25561ed2c84bd5bcb766e36fd8f211"
format_stamp: "Formatted at 2026-08-12 06:19:21 on dist-test-slave-6k22"
I20260812 06:19:21.297986 27939 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:21.298987 28068 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:21.299225 27939 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:21.299299 27939 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root
uuid: "ab25561ed2c84bd5bcb766e36fd8f211"
format_stamp: "Formatted at 2026-08-12 06:19:21 on dist-test-slave-6k22"
I20260812 06:19:21.299386 27939 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:21.318696 27939 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:21.319392 27939 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:21.319963 27939 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:21.320796 27939 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:21.320847 27939 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:21.320886 27939 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:21.320945 27939 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:21.327651 27939 rpc_server.cc:307] RPC server started. Bound to: 127.27.72.193:44459
I20260812 06:19:21.327857 28142 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.72.193:44459 every 8 connection(s)
I20260812 06:19:21.342553 28143 heartbeater.cc:344] Connected to a master server at 127.27.72.254:35103
I20260812 06:19:21.342809 28143 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:21.343318 28143 heartbeater.cc:507] Master 127.27.72.254:35103 requested a full tablet report, sending...
I20260812 06:19:21.344903 27978 ts_manager.cc:194] Registered new tserver with Master: ab25561ed2c84bd5bcb766e36fd8f211 (127.27.72.193:44459)
I20260812 06:19:21.345043 27939 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016708658s
I20260812 06:19:21.346401 27978 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48370
I20260812 06:19:21.355116 27978 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48382:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:21.370859 28100 tablet_service.cc:1511] Processing CreateTablet for tablet 3a745bc4b6f7428a9a23567a70264deb (DEFAULT_TABLE table=heavy-update-compaction-test [id=5e59bb55332049f18b5ac182a35beb2e]), partition=
I20260812 06:19:21.371348 28100 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3a745bc4b6f7428a9a23567a70264deb. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:21.373632 28159 tablet_bootstrap.cc:492] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Bootstrap starting.
I20260812 06:19:21.374792 28159 tablet_bootstrap.cc:654] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:21.376574 28159 tablet_bootstrap.cc:492] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: No bootstrap required, opened a new log
I20260812 06:19:21.376693 28159 ts_tablet_manager.cc:1403] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:21.377275 28159 raft_consensus.cc:359] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ab25561ed2c84bd5bcb766e36fd8f211" member_type: VOTER last_known_addr { host: "127.27.72.193" port: 44459 } }
I20260812 06:19:21.377411 28159 raft_consensus.cc:385] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:21.377451 28159 raft_consensus.cc:740] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ab25561ed2c84bd5bcb766e36fd8f211, State: Initialized, Role: FOLLOWER
I20260812 06:19:21.377599 28159 consensus_queue.cc:260] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211 [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: "ab25561ed2c84bd5bcb766e36fd8f211" member_type: VOTER last_known_addr { host: "127.27.72.193" port: 44459 } }
I20260812 06:19:21.377701 28159 raft_consensus.cc:399] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:21.377751 28159 raft_consensus.cc:493] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:21.377805 28159 raft_consensus.cc:3060] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:21.378819 28159 raft_consensus.cc:515] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ab25561ed2c84bd5bcb766e36fd8f211" member_type: VOTER last_known_addr { host: "127.27.72.193" port: 44459 } }
I20260812 06:19:21.378988 28159 leader_election.cc:304] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211 [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: ab25561ed2c84bd5bcb766e36fd8f211; no voters: 
I20260812 06:19:21.379212 28159 leader_election.cc:290] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:21.379335 28162 raft_consensus.cc:2804] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:21.379547 28159 ts_tablet_manager.cc:1434] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:21.379622 28162 raft_consensus.cc:697] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211 [term 1 LEADER]: Becoming Leader. State: Replica: ab25561ed2c84bd5bcb766e36fd8f211, State: Running, Role: LEADER
I20260812 06:19:21.379803 28143 heartbeater.cc:499] Master 127.27.72.254:35103 was elected leader, sending a full tablet report...
I20260812 06:19:21.379820 28162 consensus_queue.cc:237] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211 [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: "ab25561ed2c84bd5bcb766e36fd8f211" member_type: VOTER last_known_addr { host: "127.27.72.193" port: 44459 } }
I20260812 06:19:21.382782 27978 catalog_manager.cc:5719] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211 reported cstate change: term changed from 0 to 1, leader changed from <none> to ab25561ed2c84bd5bcb766e36fd8f211 (127.27.72.193). New cstate: current_term: 1 leader_uuid: "ab25561ed2c84bd5bcb766e36fd8f211" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ab25561ed2c84bd5bcb766e36fd8f211" member_type: VOTER last_known_addr { host: "127.27.72.193" port: 44459 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:21.452708 27939 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.023s	sys 0.008s
I20260812 06:19:21.578824 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushMRSOp(3a745bc4b6f7428a9a23567a70264deb): perf score=15.086190
I20260812 06:19:21.761264 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushMRSOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.182s	user 0.135s	sys 0.043s Metrics: {"bytes_written":12307492,"cfile_init":1,"compiler_manager_pool.queue_time_us":379,"delete_count":0,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":233,"dirs.run_wall_time_us":980,"drs_written":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44655,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":107,"threads_started":1,"update_count":1500}
I20260812 06:19:21.762867 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling LogGCOp(3a745bc4b6f7428a9a23567a70264deb): free 20743880 bytes of WAL
I20260812 06:19:21.763499 28074 log_reader.cc:385] T 3a745bc4b6f7428a9a23567a70264deb: removed 2 log segments from log reader
I20260812 06:19:21.763701 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000001 (ops 1-6)
I20260812 06:19:21.763849 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000002 (ops 7-11)
I20260812 06:19:21.769987 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: LogGCOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.007s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:21.770373 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling UndoDeltaBlockGCOp(3a745bc4b6f7428a9a23567a70264deb): 16411392 bytes on disk
I20260812 06:19:21.771296 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: UndoDeltaBlockGCOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":110,"lbm_reads_lt_1ms":4}
I20260812 06:19:21.771801 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:21.804610 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.033s	user 0.007s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5881,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.805094 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:21.821346 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6159,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.821960 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:22.008528 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.186s	user 0.151s	sys 0.034s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774810,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1090,"lbm_read_time_us":12588,"lbm_reads_lt_1ms":569,"lbm_write_time_us":32715,"lbm_writes_lt_1ms":543,"mutex_wait_us":330,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13056,"thread_start_us":355,"threads_started":5,"update_count":2500}
I20260812 06:19:22.009084 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=10.126437
I20260812 06:19:22.052125 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.043s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14933,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.052661 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:22.067205 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5669,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.067866 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:22.222703 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.155s	user 0.105s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":276,"lbm_read_time_us":8626,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27602,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:22.226213 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=10.126437
I20260812 06:19:22.268874 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.042s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15029,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.269311 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:22.280030 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3969,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.280684 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:22.429852 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.149s	user 0.113s	sys 0.036s 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":184,"lbm_read_time_us":10262,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28956,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15872,"update_count":2000}
I20260812 06:19:22.430502 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=10.126437
I20260812 06:19:22.478824 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.048s	user 0.019s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16169,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.479281 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:22.490293 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3958,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.490923 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:22.630048 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.139s	user 0.102s	sys 0.036s 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":755,"lbm_read_time_us":9051,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28117,"lbm_writes_lt_1ms":443,"mutex_wait_us":286,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2000}
I20260812 06:19:22.630721 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=10.126437
I20260812 06:19:22.677215 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.046s	user 0.015s	sys 0.030s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16164,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.677796 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:22.694005 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6104,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.694584 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:22.837072 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.142s	user 0.096s	sys 0.045s 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":162,"lbm_read_time_us":11254,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22246,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2000}
I20260812 06:19:22.837919 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=10.126437
I20260812 06:19:22.880595 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.042s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16665,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.881057 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:22.891785 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4062,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.892563 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:23.023838 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.131s	user 0.105s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":509,"lbm_read_time_us":9951,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25738,"lbm_writes_lt_1ms":443,"mutex_wait_us":94,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:19:23.024485 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=10.126437
I20260812 06:19:23.068681 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.044s	user 0.030s	sys 0.006s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15752,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:23.069182 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:23.079444 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4074,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.079957 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushMRSOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:23.110575 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushMRSOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.030s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1501,"drs_written":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1549,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:23.111325 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling LogGCOp(3a745bc4b6f7428a9a23567a70264deb): free 120553323 bytes of WAL
I20260812 06:19:23.111542 28074 log_reader.cc:385] T 3a745bc4b6f7428a9a23567a70264deb: removed 12 log segments from log reader
I20260812 06:19:23.111665 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000003 (ops 12-16)
I20260812 06:19:23.111718 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000004 (ops 17-21)
I20260812 06:19:23.111781 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000005 (ops 22-26)
I20260812 06:19:23.111821 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000006 (ops 27-31)
I20260812 06:19:23.111857 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000007 (ops 32-36)
I20260812 06:19:23.111894 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000008 (ops 37-41)
I20260812 06:19:23.111931 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000009 (ops 42-46)
I20260812 06:19:23.111967 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000010 (ops 47-50)
I20260812 06:19:23.112002 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000011 (ops 51-55)
I20260812 06:19:23.112038 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000012 (ops 56-60)
I20260812 06:19:23.112075 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000013 (ops 61-64)
I20260812 06:19:23.112110 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000014 (ops 65-69)
I20260812 06:19:23.138715 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: LogGCOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:23.139258 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=3.181125
I20260812 06:19:23.157397 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.018s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":6909,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:23.157835 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:23.167092 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3595,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:23.167517 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling UndoDeltaBlockGCOp(3a745bc4b6f7428a9a23567a70264deb): 462 bytes on disk
I20260812 06:19:23.168159 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: UndoDeltaBlockGCOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:19:23.168798 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:23.344661 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.176s	user 0.143s	sys 0.024s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":851,"lbm_read_time_us":11495,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36535,"lbm_writes_lt_1ms":643,"mutex_wait_us":269,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16640,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:19:23.345309 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=14.095187
I20260812 06:19:23.397624 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.052s	user 0.041s	sys 0.007s Metrics: {"bytes_written":16409946,"delete_count":0,"lbm_write_time_us":22639,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.398130 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:23.409840 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4277,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.410334 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:23.570165 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.160s	user 0.128s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774733,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":261,"lbm_read_time_us":10443,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30792,"lbm_writes_lt_1ms":543,"mutex_wait_us":65,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:23.571883 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=14.095187
I20260812 06:19:23.629406 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.057s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23679,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.629930 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:23.640707 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3942,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.641319 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:23.815763 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.174s	user 0.118s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":985,"lbm_read_time_us":12168,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31082,"lbm_writes_lt_1ms":543,"mutex_wait_us":277,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:23.816453 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=14.095187
I20260812 06:19:23.867777 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.051s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21657,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.868412 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:24.035362 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.167s	user 0.116s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":660,"lbm_read_time_us":10386,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25334,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:19:24.035913 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=14.095187
I20260812 06:19:24.085259 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.049s	user 0.016s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19761,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:24.085731 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:24.099833 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5004,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.100337 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:24.283910 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.183s	user 0.137s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":787,"lbm_read_time_us":11134,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28970,"lbm_writes_lt_1ms":543,"mutex_wait_us":71,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2500}
I20260812 06:19:24.284401 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=14.095187
I20260812 06:19:24.337446 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.053s	user 0.026s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21645,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:24.337909 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:24.349182 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4074,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.349694 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:24.495535 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.146s	user 0.105s	sys 0.038s 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":221,"lbm_read_time_us":9620,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30599,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:19:24.496217 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=11.118625
I20260812 06:19:24.544559 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.048s	user 0.037s	sys 0.007s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":19009,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:24.545178 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:24.572718 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.027s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5574,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:24.573230 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:24.583515 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4000,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.584049 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushMRSOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:24.613790 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushMRSOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":46,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1519,"drs_written":1,"lbm_read_time_us":93,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1597,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:24.614490 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling LogGCOp(3a745bc4b6f7428a9a23567a70264deb): free 124710353 bytes of WAL
I20260812 06:19:24.614724 28074 log_reader.cc:385] T 3a745bc4b6f7428a9a23567a70264deb: removed 12 log segments from log reader
I20260812 06:19:24.614773 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000015 (ops 70-74)
I20260812 06:19:24.614802 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000016 (ops 75-79)
I20260812 06:19:24.614868 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000017 (ops 80-84)
I20260812 06:19:24.614907 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000018 (ops 85-89)
I20260812 06:19:24.614951 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000019 (ops 90-94)
I20260812 06:19:24.615015 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000020 (ops 95-99)
I20260812 06:19:24.615069 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000021 (ops 100-104)
I20260812 06:19:24.615108 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000022 (ops 105-109)
I20260812 06:19:24.615147 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000023 (ops 110-114)
I20260812 06:19:24.615187 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000024 (ops 115-119)
I20260812 06:19:24.615224 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000025 (ops 120-124)
I20260812 06:19:24.615262 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000026 (ops 125-129)
I20260812 06:19:24.642437 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: LogGCOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:24.643033 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling UndoDeltaBlockGCOp(3a745bc4b6f7428a9a23567a70264deb): 482 bytes on disk
I20260812 06:19:24.643494 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: UndoDeltaBlockGCOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:19:24.644215 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=3.181125
I20260812 06:19:24.668852 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.024s	user 0.002s	sys 0.019s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4649,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:24.669425 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:24.684792 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5754,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:24.685351 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:24.913681 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.228s	user 0.174s	sys 0.052s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979849,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":454,"lbm_read_time_us":16777,"lbm_reads_lt_1ms":775,"lbm_write_time_us":38535,"lbm_writes_lt_1ms":743,"mutex_wait_us":1518,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":60288,"thread_start_us":97,"threads_started":1,"update_count":3500}
I20260812 06:19:24.914603 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=14.095187
I20260812 06:19:24.967447 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.052s	user 0.031s	sys 0.017s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22618,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:24.968179 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:24.985220 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6140,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.985683 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:25.156788 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.171s	user 0.118s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":685,"lbm_read_time_us":10303,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29196,"lbm_writes_lt_1ms":543,"mutex_wait_us":277,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2500}
I20260812 06:19:25.157428 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=14.095187
I20260812 06:19:25.219012 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.061s	user 0.041s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20932,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:25.219501 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:25.230275 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4159,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.230685 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:25.405800 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.175s	user 0.125s	sys 0.048s 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":340,"lbm_read_time_us":13439,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31360,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:19:25.406525 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=11.118625
I20260812 06:19:25.448545 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.042s	user 0.025s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18836,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:25.449122 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:25.473869 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.025s	user 0.004s	sys 0.017s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6862,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:25.474460 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:25.632640 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.158s	user 0.099s	sys 0.052s 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":174,"lbm_read_time_us":10014,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25393,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2000}
I20260812 06:19:25.633302 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=14.095187
I20260812 06:19:25.682180 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.049s	user 0.024s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18482,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:25.682775 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:25.695472 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.013s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4071,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.696116 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:25.842790 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.146s	user 0.127s	sys 0.016s 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":678,"lbm_read_time_us":11153,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27844,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24064,"update_count":2500}
I20260812 06:19:25.843328 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=11.118625
I20260812 06:19:25.878527 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.035s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14983,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:25.879117 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:25.894358 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5886,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:25.894922 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:26.027475 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.132s	user 0.108s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":151,"lbm_read_time_us":8399,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25657,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":45952,"update_count":2000}
I20260812 06:19:26.028313 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=11.118625
I20260812 06:19:26.066466 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.038s	user 0.020s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16559,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:26.067186 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:26.081022 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5080,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:26.081525 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushMRSOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:26.132831 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushMRSOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.051s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1520,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2523,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:26.133599 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling LogGCOp(3a745bc4b6f7428a9a23567a70264deb): free 121006697 bytes of WAL
I20260812 06:19:26.133865 28074 log_reader.cc:385] T 3a745bc4b6f7428a9a23567a70264deb: removed 12 log segments from log reader
I20260812 06:19:26.133932 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000027 (ops 130-134)
I20260812 06:19:26.133973 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000028 (ops 135-139)
I20260812 06:19:26.134003 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000029 (ops 140-144)
I20260812 06:19:26.134030 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000030 (ops 145-149)
I20260812 06:19:26.134057 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000031 (ops 150-154)
I20260812 06:19:26.134092 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000032 (ops 155-158)
I20260812 06:19:26.134126 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000033 (ops 159-163)
I20260812 06:19:26.134151 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000034 (ops 164-168)
I20260812 06:19:26.134181 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000035 (ops 169-173)
I20260812 06:19:26.134202 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000036 (ops 174-178)
I20260812 06:19:26.134232 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000037 (ops 179-183)
I20260812 06:19:26.134266 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000038 (ops 184-188)
I20260812 06:19:26.164937 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: LogGCOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:19:26.165392 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling UndoDeltaBlockGCOp(3a745bc4b6f7428a9a23567a70264deb): 473 bytes on disk
I20260812 06:19:26.165840 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: UndoDeltaBlockGCOp(3a745bc4b6f7428a9a23567a70264deb) 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:19:26.166365 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=6.157687
I20260812 06:19:26.190728 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.024s	user 0.020s	sys 0.000s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9814,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:26.191203 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling LogGCOp(3a745bc4b6f7428a9a23567a70264deb): free 11564893 bytes of WAL
I20260812 06:19:26.191417 28074 log_reader.cc:385] T 3a745bc4b6f7428a9a23567a70264deb: removed 1 log segments from log reader
I20260812 06:19:26.191462 28074 log.cc:1079] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/3a745bc4b6f7428a9a23567a70264deb/wal-000000039 (ops 189-192)
I20260812 06:19:26.193635 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: LogGCOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:26.193948 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=2.188937
I20260812 06:19:26.206004 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4052,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.206642 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb): perf score=1.000000
I20260812 06:19:26.380101 27939 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.927s	user 1.845s	sys 0.131s
I20260812 06:19:26.427733 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: MajorDeltaCompactionOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.221s	user 0.157s	sys 0.063s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979742,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":16598,"lbm_reads_lt_1ms":770,"lbm_write_time_us":47282,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":3500}
I20260812 06:19:26.428251 28144 maintenance_manager.cc:419] P ab25561ed2c84bd5bcb766e36fd8f211: Scheduling FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb): perf score=14.095187
I20260812 06:19:26.464227 27939 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.084s	user 0.001s	sys 0.002s
I20260812 06:19:26.465034 27939 tablet_server.cc:179] TabletServer@127.27.72.193:0 shutting down...
I20260812 06:19:26.475114 28074 maintenance_manager.cc:643] P ab25561ed2c84bd5bcb766e36fd8f211: FlushDeltaMemStoresOp(3a745bc4b6f7428a9a23567a70264deb) complete. Timing: real 0.047s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20142,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:26.475795 27939 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:26.476217 27939 tablet_replica.cc:333] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211: stopping tablet replica
I20260812 06:19:26.476449 27939 raft_consensus.cc:2243] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:26.476647 27939 raft_consensus.cc:2272] T 3a745bc4b6f7428a9a23567a70264deb P ab25561ed2c84bd5bcb766e36fd8f211 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:26.491341 27939 tablet_server.cc:196] TabletServer@127.27.72.193:0 shutdown complete.
I20260812 06:19:26.504514 27939 master.cc:562] Master@127.27.72.254:35103 shutting down...
I20260812 06:19:26.507889 27939 raft_consensus.cc:2243] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:26.508086 27939 raft_consensus.cc:2272] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:26.508174 27939 tablet_replica.cc:333] T 00000000000000000000000000000000 P cd8055a526ba4ada9f5541117d6b4f1d: stopping tablet replica
I20260812 06:19:26.520380 27939 master.cc:584] Master@127.27.72.254:35103 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5466 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:26.606017 27939 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.72.254:35947
I20260812 06:19:26.606400 27939 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:26.608616 28186 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:26.608714 28184 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:26.608747 28183 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:26.608928 27939 server_base.cc:1061] running on GCE node
I20260812 06:19:26.609048 27939 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:26.609081 27939 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:26.609095 27939 hybrid_clock.cc:648] HybridClock initialized: now 1786515566609095 us; error 0 us; skew 500 ppm
I20260812 06:19:26.609843 27939 webserver.cc:533] Webserver started at http://127.27.72.254:38825/ using document root <none> and password file <none>
I20260812 06:19:26.610023 27939 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:26.610065 27939 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:26.610126 27939 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:26.610482 27939 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/master-0-root/instance:
uuid: "f787ceffbb2a4ceb8b995c788de24804"
format_stamp: "Formatted at 2026-08-12 06:19:26 on dist-test-slave-6k22"
I20260812 06:19:26.612000 27939 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:26.612884 28192 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:26.613160 27939 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:26.613256 27939 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/master-0-root
uuid: "f787ceffbb2a4ceb8b995c788de24804"
format_stamp: "Formatted at 2026-08-12 06:19:26 on dist-test-slave-6k22"
I20260812 06:19:26.613351 27939 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:26.618741 27939 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:26.619089 27939 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:26.623229 27939 rpc_server.cc:307] RPC server started. Bound to: 127.27.72.254:35947
I20260812 06:19:26.627035 28257 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.72.254:35947 every 8 connection(s)
I20260812 06:19:26.627187 28258 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:26.641091 28258 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804: Bootstrap starting.
I20260812 06:19:26.641957 28258 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:26.643088 28258 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804: No bootstrap required, opened a new log
I20260812 06:19:26.643513 28258 raft_consensus.cc:359] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f787ceffbb2a4ceb8b995c788de24804" member_type: VOTER }
I20260812 06:19:26.643683 28258 raft_consensus.cc:385] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:26.643738 28258 raft_consensus.cc:740] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f787ceffbb2a4ceb8b995c788de24804, State: Initialized, Role: FOLLOWER
I20260812 06:19:26.643921 28258 consensus_queue.cc:260] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [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: "f787ceffbb2a4ceb8b995c788de24804" member_type: VOTER }
I20260812 06:19:26.644014 28258 raft_consensus.cc:399] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:26.644059 28258 raft_consensus.cc:493] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:26.644114 28258 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:26.644855 28258 raft_consensus.cc:515] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f787ceffbb2a4ceb8b995c788de24804" member_type: VOTER }
I20260812 06:19:26.645016 28258 leader_election.cc:304] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [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: f787ceffbb2a4ceb8b995c788de24804; no voters: 
I20260812 06:19:26.645226 28258 leader_election.cc:290] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:26.645368 28261 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:26.645613 28261 raft_consensus.cc:697] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [term 1 LEADER]: Becoming Leader. State: Replica: f787ceffbb2a4ceb8b995c788de24804, State: Running, Role: LEADER
I20260812 06:19:26.645714 28258 sys_catalog.cc:565] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:26.645779 28261 consensus_queue.cc:237] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [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: "f787ceffbb2a4ceb8b995c788de24804" member_type: VOTER }
I20260812 06:19:26.646251 28262 sys_catalog.cc:455] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f787ceffbb2a4ceb8b995c788de24804" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f787ceffbb2a4ceb8b995c788de24804" member_type: VOTER } }
I20260812 06:19:26.646373 28262 sys_catalog.cc:458] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:26.646265 28263 sys_catalog.cc:455] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [sys.catalog]: SysCatalogTable state changed. Reason: New leader f787ceffbb2a4ceb8b995c788de24804. Latest consensus state: current_term: 1 leader_uuid: "f787ceffbb2a4ceb8b995c788de24804" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f787ceffbb2a4ceb8b995c788de24804" member_type: VOTER } }
I20260812 06:19:26.646440 28263 sys_catalog.cc:458] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:26.646965 28267 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:26.647742 28267 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:26.648010 27939 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:26.649582 28267 catalog_manager.cc:1383] Generated new cluster ID: 33fed5641ad3452a89cac23b71f6cdaa
I20260812 06:19:26.649637 28267 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:26.661386 28267 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:26.661917 28267 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:26.671849 28267 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804: Generated new TSK 0
I20260812 06:19:26.672080 28267 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:26.680310 27939 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:26.682639 28282 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:26.682721 28286 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:26.682809 27939 server_base.cc:1061] running on GCE node
W20260812 06:19:26.682778 28283 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:26.683151 27939 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:26.683203 27939 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:26.683219 27939 hybrid_clock.cc:648] HybridClock initialized: now 1786515566683219 us; error 0 us; skew 500 ppm
I20260812 06:19:26.684203 27939 webserver.cc:533] Webserver started at http://127.27.72.193:35027/ using document root <none> and password file <none>
I20260812 06:19:26.684388 27939 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:26.684460 27939 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:26.684549 27939 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:26.684957 27939 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/instance:
uuid: "b7903bff7da346d9bddf0e187c884f8d"
format_stamp: "Formatted at 2026-08-12 06:19:26 on dist-test-slave-6k22"
I20260812 06:19:26.686422 27939 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:26.687314 28291 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:26.687614 27939 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:26.687690 27939 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root
uuid: "b7903bff7da346d9bddf0e187c884f8d"
format_stamp: "Formatted at 2026-08-12 06:19:26 on dist-test-slave-6k22"
I20260812 06:19:26.687783 27939 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:26.695839 27939 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:26.696185 27939 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:26.696484 27939 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:26.696943 27939 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:26.696981 27939 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:26.697039 27939 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:26.697080 27939 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:26.701329 27939 rpc_server.cc:307] RPC server started. Bound to: 127.27.72.193:34819
I20260812 06:19:26.701366 28369 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.72.193:34819 every 8 connection(s)
I20260812 06:19:26.709189 28371 heartbeater.cc:344] Connected to a master server at 127.27.72.254:35947
I20260812 06:19:26.709296 28371 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:26.709491 28371 heartbeater.cc:507] Master 127.27.72.254:35947 requested a full tablet report, sending...
I20260812 06:19:26.710076 28215 ts_manager.cc:194] Registered new tserver with Master: b7903bff7da346d9bddf0e187c884f8d (127.27.72.193:34819)
I20260812 06:19:26.710604 27939 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008825889s
I20260812 06:19:26.710786 28215 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:52480
I20260812 06:19:26.717314 28215 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:52486:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:26.726150 28327 tablet_service.cc:1511] Processing CreateTablet for tablet 332e903517ef4855b5217334155a48b5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ef8f6aa653bd4bd8b6fd9bc33b92cd93]), partition=
I20260812 06:19:26.726444 28327 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 332e903517ef4855b5217334155a48b5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:26.728614 28388 tablet_bootstrap.cc:492] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Bootstrap starting.
I20260812 06:19:26.729437 28388 tablet_bootstrap.cc:654] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:26.730567 28388 tablet_bootstrap.cc:492] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: No bootstrap required, opened a new log
I20260812 06:19:26.730679 28388 ts_tablet_manager.cc:1403] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:26.731093 28388 raft_consensus.cc:359] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b7903bff7da346d9bddf0e187c884f8d" member_type: VOTER last_known_addr { host: "127.27.72.193" port: 34819 } }
I20260812 06:19:26.731221 28388 raft_consensus.cc:385] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:26.731267 28388 raft_consensus.cc:740] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b7903bff7da346d9bddf0e187c884f8d, State: Initialized, Role: FOLLOWER
I20260812 06:19:26.731441 28388 consensus_queue.cc:260] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d [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: "b7903bff7da346d9bddf0e187c884f8d" member_type: VOTER last_known_addr { host: "127.27.72.193" port: 34819 } }
I20260812 06:19:26.731573 28388 raft_consensus.cc:399] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:26.731614 28388 raft_consensus.cc:493] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:26.731664 28388 raft_consensus.cc:3060] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:26.732425 28388 raft_consensus.cc:515] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b7903bff7da346d9bddf0e187c884f8d" member_type: VOTER last_known_addr { host: "127.27.72.193" port: 34819 } }
I20260812 06:19:26.732570 28388 leader_election.cc:304] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d [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: b7903bff7da346d9bddf0e187c884f8d; no voters: 
I20260812 06:19:26.732790 28388 leader_election.cc:290] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:26.732959 28390 raft_consensus.cc:2804] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:26.733119 28388 ts_tablet_manager.cc:1434] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:26.733130 28371 heartbeater.cc:499] Master 127.27.72.254:35947 was elected leader, sending a full tablet report...
I20260812 06:19:26.733183 28390 raft_consensus.cc:697] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d [term 1 LEADER]: Becoming Leader. State: Replica: b7903bff7da346d9bddf0e187c884f8d, State: Running, Role: LEADER
I20260812 06:19:26.733336 28390 consensus_queue.cc:237] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d [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: "b7903bff7da346d9bddf0e187c884f8d" member_type: VOTER last_known_addr { host: "127.27.72.193" port: 34819 } }
I20260812 06:19:26.734601 28215 catalog_manager.cc:5719] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d reported cstate change: term changed from 0 to 1, leader changed from <none> to b7903bff7da346d9bddf0e187c884f8d (127.27.72.193). New cstate: current_term: 1 leader_uuid: "b7903bff7da346d9bddf0e187c884f8d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b7903bff7da346d9bddf0e187c884f8d" member_type: VOTER last_known_addr { host: "127.27.72.193" port: 34819 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:26.793285 27939 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.006s	sys 0.016s
I20260812 06:19:26.952201 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushMRSOp(332e903517ef4855b5217334155a48b5): perf score=19.054940
I20260812 06:19:27.100754 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushMRSOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.148s	user 0.110s	sys 0.037s Metrics: {"bytes_written":12717735,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":280,"dirs.run_cpu_time_us":249,"dirs.run_wall_time_us":1026,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38486,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1550}
I20260812 06:19:27.101549 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:27.127786 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.026s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5381,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.128229 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling LogGCOp(332e903517ef4855b5217334155a48b5): free 20743880 bytes of WAL
I20260812 06:19:27.128432 28296 log_reader.cc:385] T 332e903517ef4855b5217334155a48b5: removed 2 log segments from log reader
I20260812 06:19:27.128497 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000001 (ops 1-6)
I20260812 06:19:27.128548 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000002 (ops 7-11)
I20260812 06:19:27.132699 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: LogGCOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:27.133023 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling UndoDeltaBlockGCOp(332e903517ef4855b5217334155a48b5): 16411397 bytes on disk
I20260812 06:19:27.133417 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: UndoDeltaBlockGCOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:19:27.133816 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:27.144414 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3871,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:27.144924 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:27.303894 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.159s	user 0.134s	sys 0.024s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":902,"lbm_read_time_us":12693,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28262,"lbm_writes_lt_1ms":543,"mutex_wait_us":118,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"thread_start_us":355,"threads_started":5,"update_count":2500}
I20260812 06:19:27.304544 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=14.095187
I20260812 06:19:27.361284 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.057s	user 0.031s	sys 0.024s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23634,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.361789 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:27.377743 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6002,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.378293 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:27.532210 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.154s	user 0.103s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":452,"lbm_read_time_us":9521,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30404,"lbm_writes_lt_1ms":543,"mutex_wait_us":115,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21376,"update_count":2500}
I20260812 06:19:27.532897 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=14.095187
I20260812 06:19:27.580979 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.048s	user 0.038s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20728,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.581470 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:27.592543 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4075,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.593195 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:27.754973 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.161s	user 0.137s	sys 0.019s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":216,"lbm_read_time_us":8884,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31972,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22400,"update_count":2500}
I20260812 06:19:27.757133 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=12.110812
I20260812 06:19:27.811908 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.055s	user 0.023s	sys 0.028s Metrics: {"bytes_written":13538210,"delete_count":0,"lbm_write_time_us":24241,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":331,"reinsert_count":0,"update_count":1650}
I20260812 06:19:27.812410 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:27.824028 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3282159,"delete_count":0,"lbm_write_time_us":3398,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:19:27.824492 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:27.834455 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3875,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:27.834920 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:28.005386 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.170s	user 0.112s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774774,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":180,"lbm_read_time_us":13465,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29622,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2500}
I20260812 06:19:28.005980 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=14.095187
I20260812 06:19:28.064595 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.058s	user 0.040s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22262,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.065088 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:28.075750 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4137,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.076153 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:28.245419 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.169s	user 0.120s	sys 0.048s 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":182,"lbm_read_time_us":12161,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28744,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:19:28.246133 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=14.095187
I20260812 06:19:28.309027 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.063s	user 0.028s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21795,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.309589 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:28.320391 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4189,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.320819 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushMRSOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:28.363183 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushMRSOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.042s	user 0.028s	sys 0.002s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":249,"dirs.run_wall_time_us":1498,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1536,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:28.363912 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling LogGCOp(332e903517ef4855b5217334155a48b5): free 120553387 bytes of WAL
I20260812 06:19:28.364149 28296 log_reader.cc:385] T 332e903517ef4855b5217334155a48b5: removed 12 log segments from log reader
I20260812 06:19:28.364192 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000003 (ops 12-16)
I20260812 06:19:28.364248 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000004 (ops 17-21)
I20260812 06:19:28.364293 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000005 (ops 22-26)
I20260812 06:19:28.364337 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000006 (ops 27-31)
I20260812 06:19:28.364379 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000007 (ops 32-36)
I20260812 06:19:28.364418 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000008 (ops 37-40)
I20260812 06:19:28.364459 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000009 (ops 41-45)
I20260812 06:19:28.364501 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000010 (ops 46-50)
I20260812 06:19:28.364540 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000011 (ops 51-54)
I20260812 06:19:28.364579 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000012 (ops 55-59)
I20260812 06:19:28.364619 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000013 (ops 60-64)
I20260812 06:19:28.364656 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000014 (ops 65-69)
I20260812 06:19:28.388933 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: LogGCOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:28.389325 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:28.409510 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.020s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4167,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.410012 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling UndoDeltaBlockGCOp(332e903517ef4855b5217334155a48b5): 472 bytes on disk
I20260812 06:19:28.410445 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: UndoDeltaBlockGCOp(332e903517ef4855b5217334155a48b5) 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:28.411007 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:28.421857 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4007,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.422596 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:28.648499 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.226s	user 0.121s	sys 0.095s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":137,"lbm_read_time_us":15252,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37616,"lbm_writes_lt_1ms":743,"mutex_wait_us":20,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":118784,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:19:28.649231 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=18.063937
I20260812 06:19:28.708338 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.059s	user 0.042s	sys 0.016s Metrics: {"bytes_written":20512320,"delete_count":0,"lbm_write_time_us":25338,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:28.708904 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:28.736371 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.027s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5726,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.736903 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:28.747942 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.011s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4180,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.748507 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:28.928700 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.180s	user 0.156s	sys 0.024s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979638,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":82,"lbm_read_time_us":12861,"lbm_reads_lt_1ms":773,"lbm_write_time_us":38538,"lbm_writes_lt_1ms":743,"mutex_wait_us":31,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":3500}
I20260812 06:19:28.929410 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=14.095187
I20260812 06:19:28.980957 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.051s	user 0.046s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22875,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.981499 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:28.993240 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4300,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.993695 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:29.141256 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.147s	user 0.112s	sys 0.035s 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":287,"lbm_read_time_us":9159,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30299,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":55040,"update_count":2500}
I20260812 06:19:29.141918 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=10.126437
I20260812 06:19:29.178853 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.037s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15795,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:29.179315 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:29.193333 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5528,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.193838 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:29.348227 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.154s	user 0.116s	sys 0.036s 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":755,"lbm_read_time_us":10908,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25958,"lbm_writes_lt_1ms":443,"mutex_wait_us":242,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:19:29.349054 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=11.118625
I20260812 06:19:29.389801 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.041s	user 0.025s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18191,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:29.390334 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:29.405329 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4633,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:29.405980 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:29.568867 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.163s	user 0.104s	sys 0.044s 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":345,"lbm_read_time_us":8100,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24013,"lbm_writes_lt_1ms":443,"mutex_wait_us":74,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2000}
I20260812 06:19:29.569682 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=14.095187
I20260812 06:19:29.627400 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.058s	user 0.031s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24593,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.627903 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:29.639394 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4011,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.639919 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:29.793476 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.153s	user 0.115s	sys 0.032s 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":863,"lbm_read_time_us":9949,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28525,"lbm_writes_lt_1ms":543,"mutex_wait_us":338,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":31744,"update_count":2500}
I20260812 06:19:29.794167 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=14.095187
I20260812 06:19:29.846104 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.052s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20487,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.846724 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:29.858016 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4105,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.858538 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushMRSOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:29.893349 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushMRSOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.035s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":147,"dirs.run_wall_time_us":1136,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2114,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:29.894029 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling LogGCOp(332e903517ef4855b5217334155a48b5): free 132571329 bytes of WAL
I20260812 06:19:29.894310 28296 log_reader.cc:385] T 332e903517ef4855b5217334155a48b5: removed 13 log segments from log reader
I20260812 06:19:29.894372 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000015 (ops 70-74)
I20260812 06:19:29.894411 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000016 (ops 75-79)
I20260812 06:19:29.894449 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000017 (ops 80-84)
I20260812 06:19:29.894475 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000018 (ops 85-88)
I20260812 06:19:29.894505 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000019 (ops 89-93)
I20260812 06:19:29.894536 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000020 (ops 94-98)
I20260812 06:19:29.894565 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000021 (ops 99-103)
I20260812 06:19:29.894600 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000022 (ops 104-108)
I20260812 06:19:29.894634 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000023 (ops 109-113)
I20260812 06:19:29.894659 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000024 (ops 114-118)
I20260812 06:19:29.894685 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000025 (ops 119-122)
I20260812 06:19:29.894713 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000026 (ops 123-127)
I20260812 06:19:29.894747 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000027 (ops 128-132)
I20260812 06:19:29.927655 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: LogGCOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.033s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:19:29.928097 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=3.181125
I20260812 06:19:29.945456 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.017s	user 0.013s	sys 0.002s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":7033,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:29.945963 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:29.955855 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3671,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:29.956555 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling UndoDeltaBlockGCOp(332e903517ef4855b5217334155a48b5): 492 bytes on disk
I20260812 06:19:29.957197 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: UndoDeltaBlockGCOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":116,"lbm_reads_lt_1ms":4}
I20260812 06:19:29.957881 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:30.152930 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.195s	user 0.155s	sys 0.040s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979736,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1123,"lbm_read_time_us":12616,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41136,"lbm_writes_lt_1ms":743,"mutex_wait_us":280,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17408,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:19:30.153736 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=14.095187
I20260812 06:19:30.202476 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.049s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":21208,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.203517 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:30.230916 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.027s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5341,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.231417 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:30.241581 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3792,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.242041 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:30.406332 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.164s	user 0.112s	sys 0.052s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877222,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":696,"lbm_read_time_us":11895,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33867,"lbm_writes_lt_1ms":643,"mutex_wait_us":291,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":26368,"update_count":3000}
I20260812 06:19:30.406955 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=14.095187
I20260812 06:19:30.455276 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.048s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":21236,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.455868 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:30.471431 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6252,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.472167 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:30.636700 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.164s	user 0.121s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":937,"lbm_read_time_us":9458,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30683,"lbm_writes_lt_1ms":543,"mutex_wait_us":305,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:19:30.637392 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=14.095187
I20260812 06:19:30.685263 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.048s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21216,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.685793 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:30.830660 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.145s	user 0.102s	sys 0.041s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":324,"lbm_read_time_us":9489,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24450,"lbm_writes_lt_1ms":443,"mutex_wait_us":88,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2000}
I20260812 06:19:30.831310 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=11.118625
I20260812 06:19:30.869962 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.038s	user 0.016s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17181,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:30.870481 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:30.882023 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4513,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:30.882674 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:31.013939 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.131s	user 0.091s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":410,"lbm_read_time_us":10317,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25132,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2000}
I20260812 06:19:31.014681 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=10.126437
I20260812 06:19:31.056304 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.041s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14432,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:31.056823 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:31.073204 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6001,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.074079 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:31.200763 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.126s	user 0.110s	sys 0.016s 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":341,"lbm_read_time_us":9582,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24088,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2000}
I20260812 06:19:31.201625 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=10.126437
I20260812 06:19:31.241132 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.039s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15420,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:31.241667 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:31.253335 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4363,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.253916 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushMRSOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:31.286525 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushMRSOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.032s	user 0.027s	sys 0.003s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":265,"dirs.run_wall_time_us":1439,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2108,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:31.287202 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling LogGCOp(332e903517ef4855b5217334155a48b5): free 121459753 bytes of WAL
I20260812 06:19:31.287446 28296 log_reader.cc:385] T 332e903517ef4855b5217334155a48b5: removed 12 log segments from log reader
I20260812 06:19:31.287492 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000028 (ops 133-137)
I20260812 06:19:31.287520 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000029 (ops 138-142)
I20260812 06:19:31.287608 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000030 (ops 143-147)
I20260812 06:19:31.287657 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000031 (ops 148-152)
I20260812 06:19:31.287716 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000032 (ops 153-157)
I20260812 06:19:31.287765 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000033 (ops 158-162)
I20260812 06:19:31.287802 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000034 (ops 163-167)
I20260812 06:19:31.287840 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000035 (ops 168-172)
I20260812 06:19:31.287880 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000036 (ops 173-177)
I20260812 06:19:31.287920 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000037 (ops 178-182)
I20260812 06:19:31.287959 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000038 (ops 183-187)
I20260812 06:19:31.287997 28296 log.cc:1079] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: Deleting log segment in path: /tmp/dist-test-task0FwWkw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515561128810-27939-0/minicluster-data/ts-0-root/wals/332e903517ef4855b5217334155a48b5/wal-000000039 (ops 188-192)
I20260812 06:19:31.313045 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: LogGCOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.026s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:31.313614 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:31.333606 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.020s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6501,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.334050 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=2.188937
I20260812 06:19:31.344866 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4335,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.345323 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling UndoDeltaBlockGCOp(332e903517ef4855b5217334155a48b5): 463 bytes on disk
I20260812 06:19:31.345999 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: UndoDeltaBlockGCOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":125,"lbm_reads_lt_1ms":4}
I20260812 06:19:31.346638 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5): perf score=1.000000
I20260812 06:19:31.462644 27939 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.669s	user 1.759s	sys 0.125s
I20260812 06:19:31.506850 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: MajorDeltaCompactionOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.160s	user 0.127s	sys 0.031s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877341,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":12506,"lbm_reads_lt_1ms":670,"lbm_write_time_us":31576,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18304,"update_count":3000}
I20260812 06:19:31.507368 28373 maintenance_manager.cc:419] P b7903bff7da346d9bddf0e187c884f8d: Scheduling FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5): perf score=10.126437
I20260812 06:19:31.532042 27939 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.069s	user 0.003s	sys 0.000s
I20260812 06:19:31.532563 27939 tablet_server.cc:179] TabletServer@127.27.72.193:0 shutting down...
I20260812 06:19:31.540809 28296 maintenance_manager.cc:643] P b7903bff7da346d9bddf0e187c884f8d: FlushDeltaMemStoresOp(332e903517ef4855b5217334155a48b5) complete. Timing: real 0.033s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14457,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:31.541477 27939 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:31.541684 27939 tablet_replica.cc:333] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d: stopping tablet replica
I20260812 06:19:31.541841 27939 raft_consensus.cc:2243] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:31.542024 27939 raft_consensus.cc:2272] T 332e903517ef4855b5217334155a48b5 P b7903bff7da346d9bddf0e187c884f8d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:31.545279 27939 tablet_server.cc:196] TabletServer@127.27.72.193:0 shutdown complete.
I20260812 06:19:31.565799 27939 master.cc:562] Master@127.27.72.254:35947 shutting down...
I20260812 06:19:31.569851 27939 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:31.570072 27939 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:31.570163 27939 tablet_replica.cc:333] T 00000000000000000000000000000000 P f787ceffbb2a4ceb8b995c788de24804: stopping tablet replica
I20260812 06:19:31.582652 27939 master.cc:584] Master@127.27.72.254:35947 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5064 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10532 ms total)

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