[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:25.556828 22844 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.22.79.62:34763
I20260812 06:20:25.557793 22844 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:25.558485 22844 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:25.565544 22853 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:25.565546 22860 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:25.565670 22844 server_base.cc:1061] running on GCE node
W20260812 06:20:25.565850 22854 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:20:25.566293 22844 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:25.566421 22844 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:25.566464 22844 hybrid_clock.cc:648] HybridClock initialized: now 1786515625566462 us; error 0 us; skew 500 ppm
I20260812 06:20:25.568188 22844 webserver.cc:533] Webserver started at http://127.22.79.62:33269/ using document root <none> and password file <none>
I20260812 06:20:25.568692 22844 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:25.568785 22844 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:25.569024 22844 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:25.570659 22844 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/master-0-root/instance:
uuid: "d8b4f3d6d5f84dd28657ceba6c8a1e6d"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-w4v5"
I20260812 06:20:25.573953 22844 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.002s
I20260812 06:20:25.575908 22869 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.576860 22844 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:25.576985 22844 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/master-0-root
uuid: "d8b4f3d6d5f84dd28657ceba6c8a1e6d"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-w4v5"
I20260812 06:20:25.577081 22844 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:25.592559 22844 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:25.593127 22844 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:25.593295 22844 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:25.600872 22844 rpc_server.cc:307] RPC server started. Bound to: 127.22.79.62:34763
I20260812 06:20:25.600900 22977 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.79.62:34763 every 8 connection(s)
I20260812 06:20:25.602967 22978 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:25.608006 22978 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d: Bootstrap starting.
I20260812 06:20:25.610246 22978 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:25.611204 22978 log.cc:826] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:25.612742 22978 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d: No bootstrap required, opened a new log
I20260812 06:20:25.615361 22978 raft_consensus.cc:359] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d8b4f3d6d5f84dd28657ceba6c8a1e6d" member_type: VOTER }
I20260812 06:20:25.615520 22978 raft_consensus.cc:385] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:25.615648 22978 raft_consensus.cc:740] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d8b4f3d6d5f84dd28657ceba6c8a1e6d, State: Initialized, Role: FOLLOWER
I20260812 06:20:25.616225 22978 consensus_queue.cc:260] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [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: "d8b4f3d6d5f84dd28657ceba6c8a1e6d" member_type: VOTER }
I20260812 06:20:25.616380 22978 raft_consensus.cc:399] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:25.616454 22978 raft_consensus.cc:493] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:25.616611 22978 raft_consensus.cc:3060] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:25.617386 22978 raft_consensus.cc:515] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d8b4f3d6d5f84dd28657ceba6c8a1e6d" member_type: VOTER }
I20260812 06:20:25.617803 22978 leader_election.cc:304] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [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: d8b4f3d6d5f84dd28657ceba6c8a1e6d; no voters: 
I20260812 06:20:25.618095 22978 leader_election.cc:290] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:25.618263 22983 raft_consensus.cc:2804] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:25.618510 22983 raft_consensus.cc:697] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [term 1 LEADER]: Becoming Leader. State: Replica: d8b4f3d6d5f84dd28657ceba6c8a1e6d, State: Running, Role: LEADER
I20260812 06:20:25.618881 22983 consensus_queue.cc:237] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [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: "d8b4f3d6d5f84dd28657ceba6c8a1e6d" member_type: VOTER }
I20260812 06:20:25.619043 22978 sys_catalog.cc:565] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:25.620661 22986 sys_catalog.cc:455] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [sys.catalog]: SysCatalogTable state changed. Reason: New leader d8b4f3d6d5f84dd28657ceba6c8a1e6d. Latest consensus state: current_term: 1 leader_uuid: "d8b4f3d6d5f84dd28657ceba6c8a1e6d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d8b4f3d6d5f84dd28657ceba6c8a1e6d" member_type: VOTER } }
I20260812 06:20:25.620723 22985 sys_catalog.cc:455] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "d8b4f3d6d5f84dd28657ceba6c8a1e6d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d8b4f3d6d5f84dd28657ceba6c8a1e6d" member_type: VOTER } }
I20260812 06:20:25.620839 22985 sys_catalog.cc:458] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:25.620781 22986 sys_catalog.cc:458] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:25.621191 22998 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:25.621467 22844 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:25.623543 22998 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:25.627785 22998 catalog_manager.cc:1383] Generated new cluster ID: 6a66603c00b643b48f9d34f7c5be6062
I20260812 06:20:25.627848 22998 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:25.634881 22998 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:25.635725 22998 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:25.642328 22998 catalog_manager.cc:6092] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d: Generated new TSK 0
I20260812 06:20:25.642933 22998 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:25.653939 22844 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:25.656641 23018 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:20:25.656620 23012 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:25.656600 23013 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:20:25.656757 22844 server_base.cc:1061] running on GCE node
I20260812 06:20:25.657158 22844 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:25.657220 22844 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:25.657246 22844 hybrid_clock.cc:648] HybridClock initialized: now 1786515625657245 us; error 0 us; skew 500 ppm
I20260812 06:20:25.658203 22844 webserver.cc:533] Webserver started at http://127.22.79.1:35099/ using document root <none> and password file <none>
I20260812 06:20:25.658381 22844 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:25.658455 22844 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:25.658536 22844 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:25.658953 22844 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/instance:
uuid: "4f066fb306734bf3a8df33f034cf770d"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-w4v5"
I20260812 06:20:25.660502 22844 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:25.661518 23029 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.661775 22844 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:25.661845 22844 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root
uuid: "4f066fb306734bf3a8df33f034cf770d"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-w4v5"
I20260812 06:20:25.661926 22844 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:25.666891 22844 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:25.667302 22844 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:25.667773 22844 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:25.668625 22844 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:25.668676 22844 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.668735 22844 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:25.668776 22844 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.675608 22844 rpc_server.cc:307] RPC server started. Bound to: 127.22.79.1:43483
I20260812 06:20:25.675663 23140 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.79.1:43483 every 8 connection(s)
I20260812 06:20:25.690922 23141 heartbeater.cc:344] Connected to a master server at 127.22.79.62:34763
I20260812 06:20:25.691200 23141 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:25.691619 23141 heartbeater.cc:507] Master 127.22.79.62:34763 requested a full tablet report, sending...
I20260812 06:20:25.692936 22900 ts_manager.cc:194] Registered new tserver with Master: 4f066fb306734bf3a8df33f034cf770d (127.22.79.1:43483)
I20260812 06:20:25.693104 22844 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016871868s
I20260812 06:20:25.694984 22900 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54124
I20260812 06:20:25.702481 22900 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54128:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:25.716414 23082 tablet_service.cc:1511] Processing CreateTablet for tablet 061a73e325934bb5ac25905c3a1983f1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=bcc10ff1932947429f1a2e86c99405a4]), partition=
I20260812 06:20:25.716853 23082 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 061a73e325934bb5ac25905c3a1983f1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:25.718972 23160 tablet_bootstrap.cc:492] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Bootstrap starting.
I20260812 06:20:25.720146 23160 tablet_bootstrap.cc:654] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:25.721390 23160 tablet_bootstrap.cc:492] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: No bootstrap required, opened a new log
I20260812 06:20:25.721522 23160 ts_tablet_manager.cc:1403] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:25.721961 23160 raft_consensus.cc:359] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4f066fb306734bf3a8df33f034cf770d" member_type: VOTER last_known_addr { host: "127.22.79.1" port: 43483 } }
I20260812 06:20:25.722064 23160 raft_consensus.cc:385] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:25.722128 23160 raft_consensus.cc:740] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4f066fb306734bf3a8df33f034cf770d, State: Initialized, Role: FOLLOWER
I20260812 06:20:25.722280 23160 consensus_queue.cc:260] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d [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: "4f066fb306734bf3a8df33f034cf770d" member_type: VOTER last_known_addr { host: "127.22.79.1" port: 43483 } }
I20260812 06:20:25.722383 23160 raft_consensus.cc:399] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:25.722431 23160 raft_consensus.cc:493] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:25.722486 23160 raft_consensus.cc:3060] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:25.723448 23160 raft_consensus.cc:515] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4f066fb306734bf3a8df33f034cf770d" member_type: VOTER last_known_addr { host: "127.22.79.1" port: 43483 } }
I20260812 06:20:25.723608 23160 leader_election.cc:304] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d [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: 4f066fb306734bf3a8df33f034cf770d; no voters: 
I20260812 06:20:25.723837 23160 leader_election.cc:290] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:25.723919 23162 raft_consensus.cc:2804] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:25.724141 23162 raft_consensus.cc:697] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d [term 1 LEADER]: Becoming Leader. State: Replica: 4f066fb306734bf3a8df33f034cf770d, State: Running, Role: LEADER
I20260812 06:20:25.724210 23160 ts_tablet_manager.cc:1434] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:20:25.724507 23141 heartbeater.cc:499] Master 127.22.79.62:34763 was elected leader, sending a full tablet report...
I20260812 06:20:25.724527 23162 consensus_queue.cc:237] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d [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: "4f066fb306734bf3a8df33f034cf770d" member_type: VOTER last_known_addr { host: "127.22.79.1" port: 43483 } }
I20260812 06:20:25.727344 22900 catalog_manager.cc:5719] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d reported cstate change: term changed from 0 to 1, leader changed from <none> to 4f066fb306734bf3a8df33f034cf770d (127.22.79.1). New cstate: current_term: 1 leader_uuid: "4f066fb306734bf3a8df33f034cf770d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4f066fb306734bf3a8df33f034cf770d" member_type: VOTER last_known_addr { host: "127.22.79.1" port: 43483 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:25.793009 22844 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.019s	sys 0.006s
I20260812 06:20:25.926719 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushMRSOp(061a73e325934bb5ac25905c3a1983f1): perf score=19.054940
I20260812 06:20:26.095268 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushMRSOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.168s	user 0.141s	sys 0.024s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":182,"delete_count":0,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":244,"dirs.run_wall_time_us":712,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44893,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":119,"threads_started":1,"update_count":1500}
I20260812 06:20:26.096478 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling LogGCOp(061a73e325934bb5ac25905c3a1983f1): free 20743880 bytes of WAL
I20260812 06:20:26.096872 23039 log_reader.cc:385] T 061a73e325934bb5ac25905c3a1983f1: removed 2 log segments from log reader
I20260812 06:20:26.096992 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000001 (ops 1-6)
I20260812 06:20:26.097095 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000002 (ops 7-11)
I20260812 06:20:26.102600 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: LogGCOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.006s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:26.103255 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling UndoDeltaBlockGCOp(061a73e325934bb5ac25905c3a1983f1): 16411391 bytes on disk
I20260812 06:20:26.103864 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: UndoDeltaBlockGCOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:20:26.104419 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=2.188937
I20260812 06:20:26.133424 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.029s	user 0.004s	sys 0.015s Metrics: {"bytes_written":4225732,"delete_count":0,"lbm_write_time_us":5782,"lbm_writes_lt_1ms":106,"mutex_wait_us":125,"reinsert_count":0,"update_count":515}
I20260812 06:20:26.133980 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=2.188937
I20260812 06:20:26.149730 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":6046,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:20:26.150195 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:26.316854 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.166s	user 0.130s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774807,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":467,"lbm_read_time_us":12125,"lbm_reads_lt_1ms":569,"lbm_write_time_us":26676,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"thread_start_us":304,"threads_started":5,"update_count":2500}
I20260812 06:20:26.317534 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=10.126437
I20260812 06:20:26.348799 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.031s	user 0.013s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13664,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.349227 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=2.188937
I20260812 06:20:26.364212 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5652,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.364794 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:26.494247 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.129s	user 0.104s	sys 0.025s 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":183,"lbm_read_time_us":8316,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26309,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":45568,"update_count":2000}
I20260812 06:20:26.494874 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=10.126437
I20260812 06:20:26.527289 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.032s	user 0.014s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13508,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.527874 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:26.642383 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.114s	user 0.097s	sys 0.014s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569747,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":328,"lbm_read_time_us":6670,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20015,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:20:26.642982 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=10.126437
I20260812 06:20:26.678844 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.036s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15596,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.679564 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:26.794370 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.115s	user 0.069s	sys 0.045s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569747,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":596,"lbm_read_time_us":7048,"lbm_reads_lt_1ms":367,"lbm_write_time_us":19000,"lbm_writes_lt_1ms":343,"mutex_wait_us":38,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:20:26.795157 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=10.126437
I20260812 06:20:26.841931 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.047s	user 0.028s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18135,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.842532 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=2.188937
I20260812 06:20:26.853427 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s 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:20:26.853946 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:26.981793 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.128s	user 0.112s	sys 0.015s 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":604,"lbm_read_time_us":7837,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26945,"lbm_writes_lt_1ms":443,"mutex_wait_us":277,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:20:26.982520 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=10.126437
I20260812 06:20:27.023546 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.041s	user 0.038s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16574,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:27.024224 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=2.188937
I20260812 06:20:27.035473 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4287,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.036154 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:27.164436 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.128s	user 0.104s	sys 0.022s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":216,"lbm_read_time_us":9323,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25263,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2000}
I20260812 06:20:27.164999 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=10.126437
I20260812 06:20:27.217693 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.053s	user 0.024s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13828,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:27.218202 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=2.188937
I20260812 06:20:27.228762 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.010s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4177,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.229161 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:27.384912 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.156s	user 0.107s	sys 0.048s 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":313,"lbm_read_time_us":10400,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25964,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2000}
I20260812 06:20:27.385532 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=10.126437
I20260812 06:20:27.418346 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.033s	user 0.013s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14260,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:27.418921 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushMRSOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:27.453828 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushMRSOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.035s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1526,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2695,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:27.454612 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling LogGCOp(061a73e325934bb5ac25905c3a1983f1): free 121006439 bytes of WAL
I20260812 06:20:27.454870 23039 log_reader.cc:385] T 061a73e325934bb5ac25905c3a1983f1: removed 12 log segments from log reader
I20260812 06:20:27.454918 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000003 (ops 12-16)
I20260812 06:20:27.454947 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000004 (ops 17-21)
I20260812 06:20:27.455008 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000005 (ops 22-26)
I20260812 06:20:27.455050 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000006 (ops 27-31)
I20260812 06:20:27.455120 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000007 (ops 32-36)
I20260812 06:20:27.455168 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000008 (ops 37-41)
I20260812 06:20:27.455235 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000009 (ops 42-46)
I20260812 06:20:27.455298 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000010 (ops 47-51)
I20260812 06:20:27.455336 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000011 (ops 52-56)
I20260812 06:20:27.455374 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000012 (ops 57-60)
I20260812 06:20:27.455415 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000013 (ops 61-65)
I20260812 06:20:27.455454 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000014 (ops 66-70)
I20260812 06:20:27.482750 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: LogGCOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.028s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:20:27.483301 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling UndoDeltaBlockGCOp(061a73e325934bb5ac25905c3a1983f1): 482 bytes on disk
I20260812 06:20:27.483816 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: UndoDeltaBlockGCOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:20:27.484337 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=6.157687
I20260812 06:20:27.509686 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.025s	user 0.022s	sys 0.001s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10945,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:27.510203 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling LogGCOp(061a73e325934bb5ac25905c3a1983f1): free 11564875 bytes of WAL
I20260812 06:20:27.510426 23039 log_reader.cc:385] T 061a73e325934bb5ac25905c3a1983f1: removed 1 log segments from log reader
I20260812 06:20:27.510470 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000015 (ops 71-74)
I20260812 06:20:27.512794 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: LogGCOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:27.513094 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:27.698643 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.185s	user 0.126s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":806,"lbm_read_time_us":11644,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29869,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":89,"threads_started":1,"update_count":2500}
I20260812 06:20:27.699213 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=14.095187
I20260812 06:20:27.752324 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.053s	user 0.036s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21876,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.752805 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=2.188937
I20260812 06:20:27.767910 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5695,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.768599 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:27.923401 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.155s	user 0.123s	sys 0.020s 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":921,"lbm_read_time_us":9652,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29975,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:27.923868 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=14.095187
I20260812 06:20:27.976692 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.053s	user 0.026s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24053,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.977116 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=2.188937
I20260812 06:20:27.988977 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4108,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.989601 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:28.138484 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.149s	user 0.117s	sys 0.024s 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":876,"lbm_read_time_us":10006,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28484,"lbm_writes_lt_1ms":543,"mutex_wait_us":322,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:28.138988 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=14.095187
I20260812 06:20:28.195278 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.056s	user 0.036s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22138,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.195772 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=2.188937
I20260812 06:20:28.206707 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4216,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.207229 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:28.353874 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.146s	user 0.120s	sys 0.016s 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":383,"lbm_read_time_us":9634,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28145,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:28.354372 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=14.095187
I20260812 06:20:28.406409 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.052s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21077,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.406891 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=2.188937
I20260812 06:20:28.418238 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4146,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.418877 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:28.588248 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.169s	user 0.134s	sys 0.027s 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":279,"lbm_read_time_us":11231,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31307,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:20:28.588829 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=14.095187
I20260812 06:20:28.638919 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.050s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22779,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.639467 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:28.797704 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.158s	user 0.107s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":183,"lbm_read_time_us":10043,"lbm_reads_lt_1ms":467,"lbm_write_time_us":27440,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:28.798219 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=11.118625
I20260812 06:20:28.840694 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.042s	user 0.021s	sys 0.020s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18204,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:28.841586 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=2.188937
I20260812 06:20:28.856389 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5556,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.856833 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushMRSOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:28.906929 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushMRSOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.050s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":192,"dirs.run_wall_time_us":1461,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2576,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:28.908682 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=6.157687
I20260812 06:20:28.937438 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.029s	user 0.015s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12409,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:28.938050 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling LogGCOp(061a73e325934bb5ac25905c3a1983f1): free 117302588 bytes of WAL
I20260812 06:20:28.938405 23039 log_reader.cc:385] T 061a73e325934bb5ac25905c3a1983f1: removed 12 log segments from log reader
I20260812 06:20:28.938452 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000016 (ops 75-79)
I20260812 06:20:28.938482 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000017 (ops 80-84)
I20260812 06:20:28.938499 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000018 (ops 85-89)
I20260812 06:20:28.938634 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000019 (ops 90-94)
I20260812 06:20:28.938699 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000020 (ops 95-98)
I20260812 06:20:28.938768 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000021 (ops 99-103)
I20260812 06:20:28.938832 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000022 (ops 104-108)
I20260812 06:20:28.938877 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000023 (ops 109-112)
I20260812 06:20:28.938923 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000024 (ops 113-117)
I20260812 06:20:28.938966 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000025 (ops 118-122)
I20260812 06:20:28.939007 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000026 (ops 123-127)
I20260812 06:20:28.939049 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000027 (ops 128-132)
I20260812 06:20:28.966475 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: LogGCOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.028s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:20:28.966972 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.196750
I20260812 06:20:28.977452 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":2707809,"delete_count":0,"lbm_write_time_us":3958,"lbm_writes_lt_1ms":69,"reinsert_count":0,"update_count":330}
I20260812 06:20:28.977854 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling UndoDeltaBlockGCOp(061a73e325934bb5ac25905c3a1983f1): 473 bytes on disk
I20260812 06:20:28.978223 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: UndoDeltaBlockGCOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:20:28.978701 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:28.983482 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.005s	user 0.004s	sys 0.000s Metrics: {"bytes_written":1395002,"delete_count":0,"lbm_write_time_us":1416,"lbm_writes_lt_1ms":37,"reinsert_count":0,"update_count":170}
I20260812 06:20:28.983806 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:29.204411 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.220s	user 0.161s	sys 0.059s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979769,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":742,"lbm_read_time_us":14642,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39498,"lbm_writes_lt_1ms":743,"mutex_wait_us":43,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":16128,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:20:29.205086 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=14.095187
I20260812 06:20:29.249989 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.045s	user 0.037s	sys 0.005s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19738,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.250597 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=2.188937
I20260812 06:20:29.267213 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.016s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6059,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.267671 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:29.439395 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.172s	user 0.106s	sys 0.065s 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":1351,"lbm_read_time_us":12949,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29655,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2500}
I20260812 06:20:29.440088 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=14.095187
I20260812 06:20:29.501495 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.061s	user 0.033s	sys 0.026s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22737,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.502051 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=2.188937
I20260812 06:20:29.512758 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4001,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.513511 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:29.692242 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.178s	user 0.128s	sys 0.041s 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":447,"lbm_read_time_us":11247,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31184,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2500}
I20260812 06:20:29.692790 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=14.095187
I20260812 06:20:29.755407 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.062s	user 0.039s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24631,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.755880 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=2.188937
I20260812 06:20:29.766607 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4381,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.767131 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:29.946059 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.179s	user 0.122s	sys 0.053s 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":332,"lbm_read_time_us":13299,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31246,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:20:29.946738 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=14.095187
I20260812 06:20:30.006206 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.059s	user 0.028s	sys 0.028s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":23333,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.006794 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=2.188937
I20260812 06:20:30.027837 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.021s	user 0.012s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7506,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.028563 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:30.206785 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.178s	user 0.108s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":209,"lbm_read_time_us":11423,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29755,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:20:30.207410 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=14.095187
I20260812 06:20:30.264813 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.057s	user 0.028s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24668,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.265393 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=2.188937
I20260812 06:20:30.295890 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.030s	user 0.012s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5368,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.296406 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=2.188937
I20260812 06:20:30.306984 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4307,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.307482 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushMRSOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:30.338522 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushMRSOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.031s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":1380,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1369,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:30.339416 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:30.530467 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.191s	user 0.134s	sys 0.057s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":174,"lbm_read_time_us":13351,"lbm_reads_lt_1ms":665,"lbm_write_time_us":34199,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20224,"update_count":3000}
I20260812 06:20:30.531198 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling LogGCOp(061a73e325934bb5ac25905c3a1983f1): free 111786500 bytes of WAL
I20260812 06:20:30.531473 23039 log_reader.cc:385] T 061a73e325934bb5ac25905c3a1983f1: removed 11 log segments from log reader
I20260812 06:20:30.531551 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000028 (ops 133-137)
I20260812 06:20:30.531666 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000029 (ops 138-142)
I20260812 06:20:30.531719 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000030 (ops 143-146)
I20260812 06:20:30.531796 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000031 (ops 147-151)
I20260812 06:20:30.531847 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000032 (ops 152-156)
I20260812 06:20:30.531888 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000033 (ops 157-161)
I20260812 06:20:30.531929 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000034 (ops 162-166)
I20260812 06:20:30.531972 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000035 (ops 167-171)
I20260812 06:20:30.532013 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000036 (ops 172-176)
I20260812 06:20:30.532058 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000037 (ops 177-180)
I20260812 06:20:30.532099 23039 log.cc:1079] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/061a73e325934bb5ac25905c3a1983f1/wal-000000038 (ops 181-185)
I20260812 06:20:30.555146 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: LogGCOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.024s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:20:30.555541 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=18.063937
I20260812 06:20:30.619351 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.064s	user 0.035s	sys 0.028s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":23732,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:30.619889 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling UndoDeltaBlockGCOp(061a73e325934bb5ac25905c3a1983f1): 447 bytes on disk
I20260812 06:20:30.620428 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: UndoDeltaBlockGCOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4}
I20260812 06:20:30.621052 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1): perf score=2.188937
I20260812 06:20:30.637266 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: FlushDeltaMemStoresOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6150,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.637773 23142 maintenance_manager.cc:419] P 4f066fb306734bf3a8df33f034cf770d: Scheduling MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1): perf score=1.000000
I20260812 06:20:30.685536 22844 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.892s	user 1.776s	sys 0.206s
I20260812 06:20:30.765938 22844 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.080s	user 0.003s	sys 0.000s
I20260812 06:20:30.766714 22844 tablet_server.cc:179] TabletServer@127.22.79.1:0 shutting down...
I20260812 06:20:30.809031 23039 maintenance_manager.cc:643] P 4f066fb306734bf3a8df33f034cf770d: MajorDeltaCompactionOp(061a73e325934bb5ac25905c3a1983f1) complete. Timing: real 0.171s	user 0.103s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1174,"lbm_read_time_us":14980,"lbm_reads_lt_1ms":668,"lbm_write_time_us":30456,"lbm_writes_lt_1ms":643,"mutex_wait_us":335,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":3000}
I20260812 06:20:30.809682 22844 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:30.810138 22844 tablet_replica.cc:333] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d: stopping tablet replica
I20260812 06:20:30.810379 22844 raft_consensus.cc:2243] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:30.810637 22844 raft_consensus.cc:2272] T 061a73e325934bb5ac25905c3a1983f1 P 4f066fb306734bf3a8df33f034cf770d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:30.826817 22844 tablet_server.cc:196] TabletServer@127.22.79.1:0 shutdown complete.
I20260812 06:20:30.861622 22844 master.cc:562] Master@127.22.79.62:34763 shutting down...
I20260812 06:20:30.865383 22844 raft_consensus.cc:2243] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:30.865594 22844 raft_consensus.cc:2272] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:30.865692 22844 tablet_replica.cc:333] T 00000000000000000000000000000000 P d8b4f3d6d5f84dd28657ceba6c8a1e6d: stopping tablet replica
I20260812 06:20:30.878269 22844 master.cc:584] Master@127.22.79.62:34763 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5413 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:30.981561 22844 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.22.79.62:46195
I20260812 06:20:30.981992 22844 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:20:30.984122 22844 server_base.cc:1061] running on GCE node
W20260812 06:20:30.984083 23195 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:30.984160 23196 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:30.984077 23199 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:30.984472 22844 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:30.984516 22844 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:30.984531 22844 hybrid_clock.cc:648] HybridClock initialized: now 1786515630984531 us; error 0 us; skew 500 ppm
I20260812 06:20:30.985356 22844 webserver.cc:533] Webserver started at http://127.22.79.62:33723/ using document root <none> and password file <none>
I20260812 06:20:30.985486 22844 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:30.985530 22844 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:30.985580 22844 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:30.985930 22844 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/master-0-root/instance:
uuid: "13a4428b2c1b4f91a7ead80e20700eac"
format_stamp: "Formatted at 2026-08-12 06:20:30 on dist-test-slave-w4v5"
I20260812 06:20:30.987392 22844 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:30.988261 23207 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:30.988565 22844 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:30.988631 22844 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/master-0-root
uuid: "13a4428b2c1b4f91a7ead80e20700eac"
format_stamp: "Formatted at 2026-08-12 06:20:30 on dist-test-slave-w4v5"
I20260812 06:20:30.988696 22844 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:31.000085 22844 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:31.000448 22844 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:31.004390 22844 rpc_server.cc:307] RPC server started. Bound to: 127.22.79.62:46195
I20260812 06:20:31.009742 23296 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.79.62:46195 every 8 connection(s)
I20260812 06:20:31.010228 23297 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:31.012100 23297 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac: Bootstrap starting.
I20260812 06:20:31.012912 23297 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:31.013957 23297 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac: No bootstrap required, opened a new log
I20260812 06:20:31.014376 23297 raft_consensus.cc:359] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "13a4428b2c1b4f91a7ead80e20700eac" member_type: VOTER }
I20260812 06:20:31.014463 23297 raft_consensus.cc:385] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:31.014523 23297 raft_consensus.cc:740] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 13a4428b2c1b4f91a7ead80e20700eac, State: Initialized, Role: FOLLOWER
I20260812 06:20:31.014703 23297 consensus_queue.cc:260] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [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: "13a4428b2c1b4f91a7ead80e20700eac" member_type: VOTER }
I20260812 06:20:31.014775 23297 raft_consensus.cc:399] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:31.014846 23297 raft_consensus.cc:493] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:31.014909 23297 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:31.015602 23297 raft_consensus.cc:515] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "13a4428b2c1b4f91a7ead80e20700eac" member_type: VOTER }
I20260812 06:20:31.015748 23297 leader_election.cc:304] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [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: 13a4428b2c1b4f91a7ead80e20700eac; no voters: 
I20260812 06:20:31.015957 23297 leader_election.cc:290] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:31.016096 23301 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:31.016350 23301 raft_consensus.cc:697] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [term 1 LEADER]: Becoming Leader. State: Replica: 13a4428b2c1b4f91a7ead80e20700eac, State: Running, Role: LEADER
I20260812 06:20:31.016463 23297 sys_catalog.cc:565] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:31.016518 23301 consensus_queue.cc:237] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [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: "13a4428b2c1b4f91a7ead80e20700eac" member_type: VOTER }
I20260812 06:20:31.016952 23302 sys_catalog.cc:455] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "13a4428b2c1b4f91a7ead80e20700eac" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "13a4428b2c1b4f91a7ead80e20700eac" member_type: VOTER } }
I20260812 06:20:31.017066 23302 sys_catalog.cc:458] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:31.017287 23303 sys_catalog.cc:455] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [sys.catalog]: SysCatalogTable state changed. Reason: New leader 13a4428b2c1b4f91a7ead80e20700eac. Latest consensus state: current_term: 1 leader_uuid: "13a4428b2c1b4f91a7ead80e20700eac" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "13a4428b2c1b4f91a7ead80e20700eac" member_type: VOTER } }
I20260812 06:20:31.017371 23303 sys_catalog.cc:458] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:31.017786 23315 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:31.018548 23315 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:31.018819 22844 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:31.020416 23315 catalog_manager.cc:1383] Generated new cluster ID: 1cfd675d94d8459ebfe2a8b05af411c4
I20260812 06:20:31.020478 23315 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:31.046424 23315 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:31.046990 23315 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:31.054265 23315 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac: Generated new TSK 0
I20260812 06:20:31.054431 23315 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:31.083518 22844 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:31.085851 23330 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:31.085917 23335 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:20:31.085886 23329 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:31.086211 22844 server_base.cc:1061] running on GCE node
I20260812 06:20:31.086378 22844 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:31.086417 22844 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:31.086433 22844 hybrid_clock.cc:648] HybridClock initialized: now 1786515631086433 us; error 0 us; skew 500 ppm
I20260812 06:20:31.087355 22844 webserver.cc:533] Webserver started at http://127.22.79.1:34465/ using document root <none> and password file <none>
I20260812 06:20:31.087494 22844 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:31.087538 22844 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:31.087591 22844 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:31.087955 22844 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/instance:
uuid: "290f60ad38804a03ad473c376687a2d1"
format_stamp: "Formatted at 2026-08-12 06:20:31 on dist-test-slave-w4v5"
I20260812 06:20:31.089403 22844 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:31.090389 23341 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:31.090749 22844 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:31.090824 22844 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root
uuid: "290f60ad38804a03ad473c376687a2d1"
format_stamp: "Formatted at 2026-08-12 06:20:31 on dist-test-slave-w4v5"
I20260812 06:20:31.090883 22844 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:31.104983 22844 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:31.105311 22844 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:31.105573 22844 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:31.106076 22844 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:31.106120 22844 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:31.106184 22844 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:31.106230 22844 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:31.111027 22844 rpc_server.cc:307] RPC server started. Bound to: 127.22.79.1:39181
I20260812 06:20:31.112798 23459 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.79.1:39181 every 8 connection(s)
I20260812 06:20:31.122223 23464 heartbeater.cc:344] Connected to a master server at 127.22.79.62:46195
I20260812 06:20:31.122362 23464 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:31.122641 23464 heartbeater.cc:507] Master 127.22.79.62:46195 requested a full tablet report, sending...
I20260812 06:20:31.123370 23232 ts_manager.cc:194] Registered new tserver with Master: 290f60ad38804a03ad473c376687a2d1 (127.22.79.1:39181)
I20260812 06:20:31.124217 23232 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50450
I20260812 06:20:31.124346 22844 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012318374s
I20260812 06:20:31.131896 23232 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50458:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:31.141855 23390 tablet_service.cc:1511] Processing CreateTablet for tablet 458f164577a241a1ba0a3a2bdb8c8c7e (DEFAULT_TABLE table=heavy-update-compaction-test [id=3b9d7824101e499cbec88e63543ac6e4]), partition=
I20260812 06:20:31.142207 23390 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 458f164577a241a1ba0a3a2bdb8c8c7e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:31.144933 23492 tablet_bootstrap.cc:492] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Bootstrap starting.
I20260812 06:20:31.146230 23492 tablet_bootstrap.cc:654] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:31.147526 23492 tablet_bootstrap.cc:492] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: No bootstrap required, opened a new log
I20260812 06:20:31.147639 23492 ts_tablet_manager.cc:1403] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:31.148033 23492 raft_consensus.cc:359] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "290f60ad38804a03ad473c376687a2d1" member_type: VOTER last_known_addr { host: "127.22.79.1" port: 39181 } }
I20260812 06:20:31.148145 23492 raft_consensus.cc:385] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:31.148197 23492 raft_consensus.cc:740] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 290f60ad38804a03ad473c376687a2d1, State: Initialized, Role: FOLLOWER
I20260812 06:20:31.148339 23492 consensus_queue.cc:260] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1 [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: "290f60ad38804a03ad473c376687a2d1" member_type: VOTER last_known_addr { host: "127.22.79.1" port: 39181 } }
I20260812 06:20:31.148452 23492 raft_consensus.cc:399] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:31.148497 23492 raft_consensus.cc:493] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:31.148561 23492 raft_consensus.cc:3060] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:31.149299 23492 raft_consensus.cc:515] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "290f60ad38804a03ad473c376687a2d1" member_type: VOTER last_known_addr { host: "127.22.79.1" port: 39181 } }
I20260812 06:20:31.149456 23492 leader_election.cc:304] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1 [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: 290f60ad38804a03ad473c376687a2d1; no voters: 
I20260812 06:20:31.149691 23492 leader_election.cc:290] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:31.149781 23494 raft_consensus.cc:2804] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:31.149950 23494 raft_consensus.cc:697] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1 [term 1 LEADER]: Becoming Leader. State: Replica: 290f60ad38804a03ad473c376687a2d1, State: Running, Role: LEADER
I20260812 06:20:31.150045 23492 ts_tablet_manager.cc:1434] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:31.150085 23494 consensus_queue.cc:237] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1 [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: "290f60ad38804a03ad473c376687a2d1" member_type: VOTER last_known_addr { host: "127.22.79.1" port: 39181 } }
I20260812 06:20:31.150279 23464 heartbeater.cc:499] Master 127.22.79.62:46195 was elected leader, sending a full tablet report...
I20260812 06:20:31.154460 23232 catalog_manager.cc:5719] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1 reported cstate change: term changed from 0 to 1, leader changed from <none> to 290f60ad38804a03ad473c376687a2d1 (127.22.79.1). New cstate: current_term: 1 leader_uuid: "290f60ad38804a03ad473c376687a2d1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "290f60ad38804a03ad473c376687a2d1" member_type: VOTER last_known_addr { host: "127.22.79.1" port: 39181 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:31.223809 22844 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.062s	user 0.016s	sys 0.015s
I20260812 06:20:31.363361 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushMRSOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=19.054940
I20260812 06:20:31.533396 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushMRSOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.170s	user 0.104s	sys 0.064s Metrics: {"bytes_written":12307489,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1061,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44395,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:20:31.534051 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling LogGCOp(458f164577a241a1ba0a3a2bdb8c8c7e): free 20743831 bytes of WAL
I20260812 06:20:31.534293 23349 log_reader.cc:385] T 458f164577a241a1ba0a3a2bdb8c8c7e: removed 2 log segments from log reader
I20260812 06:20:31.534341 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000001 (ops 1-6)
I20260812 06:20:31.534371 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000002 (ops 7-11)
I20260812 06:20:31.538606 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: LogGCOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:31.539026 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling UndoDeltaBlockGCOp(458f164577a241a1ba0a3a2bdb8c8c7e): 16411392 bytes on disk
I20260812 06:20:31.539660 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: UndoDeltaBlockGCOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4}
I20260812 06:20:31.540145 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:31.557204 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6620,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.557662 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:31.715245 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.157s	user 0.117s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":927,"lbm_read_time_us":9551,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25382,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":339,"threads_started":5,"update_count":2000}
I20260812 06:20:31.715898 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=14.095187
I20260812 06:20:31.780228 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.064s	user 0.028s	sys 0.034s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24346,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.780797 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:31.792621 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4616,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.793093 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:31.977530 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.184s	user 0.115s	sys 0.067s 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":211,"lbm_read_time_us":13653,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27352,"lbm_writes_lt_1ms":543,"mutex_wait_us":90,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2500}
I20260812 06:20:31.978096 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=14.095187
I20260812 06:20:32.030661 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.052s	user 0.035s	sys 0.011s Metrics: {"bytes_written":16409936,"delete_count":0,"lbm_write_time_us":21782,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.031229 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:32.053174 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.022s	user 0.009s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4409,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.053910 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:32.226245 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.172s	user 0.092s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":224,"lbm_read_time_us":11413,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28673,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20096,"update_count":2500}
I20260812 06:20:32.226872 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=14.095187
I20260812 06:20:32.272931 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.046s	user 0.033s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20533,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.273487 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:32.293275 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.020s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6048,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":500}
I20260812 06:20:32.293788 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:32.476327 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.182s	user 0.124s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1102,"lbm_read_time_us":9928,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30773,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:20:32.476989 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=14.095187
I20260812 06:20:32.519219 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.042s	user 0.015s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18779,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.519789 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:32.537408 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.017s	user 0.002s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6565,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.537954 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:32.700991 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.163s	user 0.119s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":660,"lbm_read_time_us":10835,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33875,"lbm_writes_lt_1ms":543,"mutex_wait_us":285,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:32.703438 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=14.095187
I20260812 06:20:32.754464 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.051s	user 0.025s	sys 0.018s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20513,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.754907 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:32.771136 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.016s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6327,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.771816 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushMRSOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:32.800796 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushMRSOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.029s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":1464,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1842,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:32.801537 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling LogGCOp(458f164577a241a1ba0a3a2bdb8c8c7e): free 120553374 bytes of WAL
I20260812 06:20:32.801823 23349 log_reader.cc:385] T 458f164577a241a1ba0a3a2bdb8c8c7e: removed 12 log segments from log reader
I20260812 06:20:32.801885 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000003 (ops 12-16)
I20260812 06:20:32.801925 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000004 (ops 17-21)
I20260812 06:20:32.801956 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000005 (ops 22-26)
I20260812 06:20:32.801985 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000006 (ops 27-31)
I20260812 06:20:32.802016 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000007 (ops 32-36)
I20260812 06:20:32.802050 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000008 (ops 37-40)
I20260812 06:20:32.802083 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000009 (ops 41-45)
I20260812 06:20:32.802112 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000010 (ops 46-50)
I20260812 06:20:32.802140 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000011 (ops 51-55)
I20260812 06:20:32.802168 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000012 (ops 56-60)
I20260812 06:20:32.802199 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000013 (ops 61-64)
I20260812 06:20:32.802233 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000014 (ops 65-69)
I20260812 06:20:32.831915 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: LogGCOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:20:32.832381 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:32.852056 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.019s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5632,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.852522 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:32.863034 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3895,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.863598 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:33.104436 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.241s	user 0.162s	sys 0.065s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":992,"lbm_read_time_us":14194,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39813,"lbm_writes_lt_1ms":743,"mutex_wait_us":335,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6272,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:20:33.105134 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=18.063937
I20260812 06:20:33.178182 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.073s	user 0.051s	sys 0.019s Metrics: {"bytes_written":20512320,"delete_count":0,"lbm_write_time_us":28936,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:33.178762 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling UndoDeltaBlockGCOp(458f164577a241a1ba0a3a2bdb8c8c7e): 462 bytes on disk
I20260812 06:20:33.179279 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: UndoDeltaBlockGCOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:20:33.179736 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:33.191159 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.011s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4406,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.191604 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:33.387338 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.196s	user 0.130s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877106,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":713,"lbm_read_time_us":15696,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32780,"lbm_writes_lt_1ms":643,"mutex_wait_us":329,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":49664,"update_count":3000}
I20260812 06:20:33.388149 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=14.095187
I20260812 06:20:33.440907 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.053s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23189,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:33.441496 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:33.457331 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.016s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6139,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.457872 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:33.633096 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.175s	user 0.115s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":507,"lbm_read_time_us":13651,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27713,"lbm_writes_lt_1ms":543,"mutex_wait_us":91,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2500}
I20260812 06:20:33.634068 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=14.095187
I20260812 06:20:33.705679 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.071s	user 0.046s	sys 0.022s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":26488,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:33.706480 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:33.718683 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.012s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4171,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.719350 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:33.898715 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.179s	user 0.114s	sys 0.061s 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":1001,"lbm_read_time_us":13150,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28021,"lbm_writes_lt_1ms":543,"mutex_wait_us":259,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:20:33.899274 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=14.095187
I20260812 06:20:33.963397 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.064s	user 0.033s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21082,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:33.963881 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:33.974426 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4111,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.974910 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:34.161356 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.186s	user 0.117s	sys 0.058s 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":668,"lbm_read_time_us":11874,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30389,"lbm_writes_lt_1ms":543,"mutex_wait_us":287,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:20:34.162078 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=14.095187
I20260812 06:20:34.220553 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.058s	user 0.041s	sys 0.013s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24706,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:34.221017 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:34.242219 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.021s	user 0.007s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4041,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:34.242834 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushMRSOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:34.276062 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushMRSOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1227,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1706,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:34.276700 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling LogGCOp(458f164577a241a1ba0a3a2bdb8c8c7e): free 112239316 bytes of WAL
I20260812 06:20:34.276930 23349 log_reader.cc:385] T 458f164577a241a1ba0a3a2bdb8c8c7e: removed 11 log segments from log reader
I20260812 06:20:34.276974 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000015 (ops 70-74)
I20260812 06:20:34.277004 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000016 (ops 75-79)
I20260812 06:20:34.277058 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000017 (ops 80-84)
I20260812 06:20:34.277104 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000018 (ops 85-89)
I20260812 06:20:34.277134 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000019 (ops 90-94)
I20260812 06:20:34.277184 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000020 (ops 95-99)
I20260812 06:20:34.277244 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000021 (ops 100-104)
I20260812 06:20:34.277288 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000022 (ops 105-108)
I20260812 06:20:34.277328 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000023 (ops 109-113)
I20260812 06:20:34.277369 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000024 (ops 114-118)
I20260812 06:20:34.277407 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000025 (ops 119-123)
I20260812 06:20:34.303426 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: LogGCOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:34.303912 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:34.329619 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.026s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5842,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":500}
I20260812 06:20:34.330119 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling UndoDeltaBlockGCOp(458f164577a241a1ba0a3a2bdb8c8c7e): 448 bytes on disk
I20260812 06:20:34.330575 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: UndoDeltaBlockGCOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:20:34.331197 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:34.342403 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4274,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:34.343230 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:34.603053 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.260s	user 0.149s	sys 0.089s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2263,"lbm_read_time_us":17025,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41134,"lbm_writes_lt_1ms":743,"mutex_wait_us":37,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":7936,"thread_start_us":104,"threads_started":1,"update_count":3500}
I20260812 06:20:34.603960 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=22.032687
I20260812 06:20:34.698467 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.094s	user 0.047s	sys 0.030s Metrics: {"bytes_written":24614720,"delete_count":0,"lbm_write_time_us":38243,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":601,"reinsert_count":0,"update_count":3000}
I20260812 06:20:34.699012 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=6.157687
I20260812 06:20:34.725909 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.027s	user 0.013s	sys 0.009s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10350,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:34.726398 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:34.972852 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.246s	user 0.165s	sys 0.071s Metrics: {"cfile_cache_miss":832,"cfile_cache_miss_bytes":37081920,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":561,"lbm_read_time_us":16925,"lbm_reads_lt_1ms":864,"lbm_write_time_us":42265,"lbm_writes_lt_1ms":843,"mutex_wait_us":292,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":4000}
I20260812 06:20:34.973562 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=22.032687
I20260812 06:20:35.049801 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.076s	user 0.056s	sys 0.017s Metrics: {"bytes_written":24614720,"delete_count":0,"lbm_write_time_us":35263,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":601,"reinsert_count":0,"update_count":3000}
I20260812 06:20:35.050385 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:35.067005 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.016s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4385,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.067478 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:35.077615 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3906,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.078047 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:35.303462 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.225s	user 0.161s	sys 0.053s Metrics: {"cfile_cache_miss":833,"cfile_cache_miss_bytes":37082036,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1073,"lbm_read_time_us":15471,"lbm_reads_lt_1ms":873,"lbm_write_time_us":45250,"lbm_writes_lt_1ms":843,"mutex_wait_us":387,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":4000}
I20260812 06:20:35.304337 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=15.087375
I20260812 06:20:35.363520 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.056s	user 0.036s	sys 0.017s Metrics: {"bytes_written":17804727,"delete_count":0,"lbm_write_time_us":24115,"lbm_writes_lt_1ms":437,"reinsert_count":0,"update_count":2170}
I20260812 06:20:35.364171 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.196750
I20260812 06:20:35.396515 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.032s	user 0.006s	sys 0.005s Metrics: {"bytes_written":2707805,"delete_count":0,"lbm_write_time_us":4303,"lbm_writes_lt_1ms":69,"reinsert_count":0,"update_count":330}
I20260812 06:20:35.396991 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:35.411325 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.014s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5644,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.411806 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:35.664506 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.253s	user 0.186s	sys 0.053s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877191,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":210,"lbm_read_time_us":14281,"lbm_reads_lt_1ms":673,"lbm_write_time_us":44106,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":3000}
I20260812 06:20:35.665256 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=18.063937
I20260812 06:20:35.732996 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.068s	user 0.035s	sys 0.028s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":28872,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:35.733515 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:35.744453 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3906,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.744990 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushMRSOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:35.779821 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushMRSOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.035s	user 0.027s	sys 0.005s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":225,"dirs.run_wall_time_us":1055,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":3973,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":38,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:35.780616 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling LogGCOp(458f164577a241a1ba0a3a2bdb8c8c7e): free 124257542 bytes of WAL
I20260812 06:20:35.780916 23349 log_reader.cc:385] T 458f164577a241a1ba0a3a2bdb8c8c7e: removed 12 log segments from log reader
I20260812 06:20:35.780998 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000026 (ops 124-128)
I20260812 06:20:35.781064 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000027 (ops 129-133)
I20260812 06:20:35.781132 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000028 (ops 134-138)
I20260812 06:20:35.781183 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000029 (ops 139-143)
I20260812 06:20:35.781226 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000030 (ops 144-148)
I20260812 06:20:35.781270 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000031 (ops 149-153)
I20260812 06:20:35.781312 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000032 (ops 154-158)
I20260812 06:20:35.781358 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000033 (ops 159-163)
I20260812 06:20:35.781399 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000034 (ops 164-168)
I20260812 06:20:35.781445 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000035 (ops 169-173)
I20260812 06:20:35.781486 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000036 (ops 174-178)
I20260812 06:20:35.781529 23349 log.cc:1079] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: Deleting log segment in path: /tmp/dist-test-task9xmoEC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625545936-22844-0/minicluster-data/ts-0-root/wals/458f164577a241a1ba0a3a2bdb8c8c7e/wal-000000037 (ops 179-182)
I20260812 06:20:35.814076 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: LogGCOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:35.815548 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=4.173312
I20260812 06:20:35.837059 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.021s	user 0.014s	sys 0.005s Metrics: {"bytes_written":5374416,"delete_count":0,"lbm_write_time_us":8837,"lbm_writes_lt_1ms":134,"reinsert_count":0,"update_count":655}
I20260812 06:20:35.837605 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling UndoDeltaBlockGCOp(458f164577a241a1ba0a3a2bdb8c8c7e): 472 bytes on disk
I20260812 06:20:35.838073 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: UndoDeltaBlockGCOp(458f164577a241a1ba0a3a2bdb8c8c7e) 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:20:35.838670 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.196750
I20260812 06:20:35.848841 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":3537,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:20:35.849434 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:36.066823 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.217s	user 0.177s	sys 0.040s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082137,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":371,"lbm_read_time_us":17088,"lbm_reads_lt_1ms":874,"lbm_write_time_us":45603,"lbm_writes_lt_1ms":843,"mutex_wait_us":27,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":208512,"thread_start_us":78,"threads_started":1,"update_count":4000}
I20260812 06:20:36.068697 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=18.063937
I20260812 06:20:36.128803 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.060s	user 0.035s	sys 0.019s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":24410,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:36.129520 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:36.158906 22844 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.935s	user 1.830s	sys 0.189s
I20260812 06:20:36.160518 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.031s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6964,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.161024 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=2.188937
I20260812 06:20:36.172022 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: FlushDeltaMemStoresOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4481,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.172434 23465 maintenance_manager.cc:419] P 290f60ad38804a03ad473c376687a2d1: Scheduling MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e): perf score=1.000000
I20260812 06:20:36.213719 22844 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.054s	user 0.001s	sys 0.000s
I20260812 06:20:36.214215 22844 tablet_server.cc:179] TabletServer@127.22.79.1:0 shutting down...
I20260812 06:20:36.320561 23349 maintenance_manager.cc:643] P 290f60ad38804a03ad473c376687a2d1: MajorDeltaCompactionOp(458f164577a241a1ba0a3a2bdb8c8c7e) complete. Timing: real 0.148s	user 0.120s	sys 0.027s Metrics: {"cfile_cache_hit":375,"cfile_cache_hit_bytes":15305217,"cfile_cache_miss":358,"cfile_cache_miss_bytes":17674418,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":895,"lbm_read_time_us":6390,"lbm_reads_lt_1ms":390,"lbm_write_time_us":33399,"lbm_writes_lt_1ms":743,"mutex_wait_us":78,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":98304,"update_count":3500}
I20260812 06:20:36.321230 22844 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:36.321482 22844 tablet_replica.cc:333] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1: stopping tablet replica
I20260812 06:20:36.321791 22844 raft_consensus.cc:2243] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:36.322021 22844 raft_consensus.cc:2272] T 458f164577a241a1ba0a3a2bdb8c8c7e P 290f60ad38804a03ad473c376687a2d1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:36.326156 22844 tablet_server.cc:196] TabletServer@127.22.79.1:0 shutdown complete.
I20260812 06:20:36.380065 22844 master.cc:562] Master@127.22.79.62:46195 shutting down...
I20260812 06:20:36.384137 22844 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:36.384320 22844 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:36.384370 22844 tablet_replica.cc:333] T 00000000000000000000000000000000 P 13a4428b2c1b4f91a7ead80e20700eac: stopping tablet replica
I20260812 06:20:36.397677 22844 master.cc:584] Master@127.22.79.62:46195 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5515 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10930 ms total)

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