[==========] 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:23.815901 16742 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.16.89.190:35669
I20260812 06:20:23.816987 16742 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:23.817606 16742 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:23.824666 16751 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:23.824702 16750 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:23.824717 16742 server_base.cc:1061] running on GCE node
W20260812 06:20:23.824680 16753 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:23.825409 16742 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:23.825510 16742 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:23.825536 16742 hybrid_clock.cc:648] HybridClock initialized: now 1786515623825534 us; error 0 us; skew 500 ppm
I20260812 06:20:23.827350 16742 webserver.cc:533] Webserver started at http://127.16.89.190:42701/ using document root <none> and password file <none>
I20260812 06:20:23.827881 16742 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:23.827939 16742 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:23.828132 16742 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:23.829854 16742 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/master-0-root/instance:
uuid: "8872b7e85adf490992e804a084c11bb9"
format_stamp: "Formatted at 2026-08-12 06:20:23 on dist-test-slave-8n49"
I20260812 06:20:23.833546 16742 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:20:23.835635 16759 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:23.836928 16742 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:23.837062 16742 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/master-0-root
uuid: "8872b7e85adf490992e804a084c11bb9"
format_stamp: "Formatted at 2026-08-12 06:20:23 on dist-test-slave-8n49"
I20260812 06:20:23.837173 16742 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-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:23.866287 16742 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:23.866989 16742 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:23.867185 16742 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:23.875833 16822 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.89.190:35669 every 8 connection(s)
I20260812 06:20:23.875850 16742 rpc_server.cc:307] RPC server started. Bound to: 127.16.89.190:35669
I20260812 06:20:23.878144 16823 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:23.883690 16823 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9: Bootstrap starting.
I20260812 06:20:23.886096 16823 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:23.887010 16823 log.cc:826] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:23.888829 16823 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9: No bootstrap required, opened a new log
I20260812 06:20:23.891609 16823 raft_consensus.cc:359] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8872b7e85adf490992e804a084c11bb9" member_type: VOTER }
I20260812 06:20:23.891765 16823 raft_consensus.cc:385] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:23.891839 16823 raft_consensus.cc:740] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8872b7e85adf490992e804a084c11bb9, State: Initialized, Role: FOLLOWER
I20260812 06:20:23.892477 16823 consensus_queue.cc:260] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [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: "8872b7e85adf490992e804a084c11bb9" member_type: VOTER }
I20260812 06:20:23.892673 16823 raft_consensus.cc:399] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:23.892778 16823 raft_consensus.cc:493] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:23.892917 16823 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:23.893721 16823 raft_consensus.cc:515] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8872b7e85adf490992e804a084c11bb9" member_type: VOTER }
I20260812 06:20:23.894156 16823 leader_election.cc:304] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [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: 8872b7e85adf490992e804a084c11bb9; no voters: 
I20260812 06:20:23.894471 16823 leader_election.cc:290] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:23.894630 16826 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:23.894882 16826 raft_consensus.cc:697] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [term 1 LEADER]: Becoming Leader. State: Replica: 8872b7e85adf490992e804a084c11bb9, State: Running, Role: LEADER
I20260812 06:20:23.895335 16826 consensus_queue.cc:237] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [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: "8872b7e85adf490992e804a084c11bb9" member_type: VOTER }
I20260812 06:20:23.895431 16823 sys_catalog.cc:565] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:23.897259 16829 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 8872b7e85adf490992e804a084c11bb9. Latest consensus state: current_term: 1 leader_uuid: "8872b7e85adf490992e804a084c11bb9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8872b7e85adf490992e804a084c11bb9" member_type: VOTER } }
I20260812 06:20:23.897289 16828 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "8872b7e85adf490992e804a084c11bb9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8872b7e85adf490992e804a084c11bb9" member_type: VOTER } }
I20260812 06:20:23.897409 16829 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:23.897409 16828 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:23.897723 16742 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:20:23.899569 16844 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:23.899664 16844 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:23.899745 16842 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:23.900529 16842 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:23.905550 16842 catalog_manager.cc:1383] Generated new cluster ID: a37c032ae6804e08a91d7b392420219e
I20260812 06:20:23.905620 16842 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:23.915481 16842 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:23.916339 16842 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:23.928269 16842 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9: Generated new TSK 0
I20260812 06:20:23.928982 16842 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:23.962553 16742 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:23.965309 16849 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:23.965351 16848 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:23.965415 16851 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:23.965699 16742 server_base.cc:1061] running on GCE node
I20260812 06:20:23.965942 16742 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:23.966003 16742 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:23.966029 16742 hybrid_clock.cc:648] HybridClock initialized: now 1786515623966029 us; error 0 us; skew 500 ppm
I20260812 06:20:23.966898 16742 webserver.cc:533] Webserver started at http://127.16.89.129:45671/ using document root <none> and password file <none>
I20260812 06:20:23.967073 16742 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:23.967147 16742 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:23.967226 16742 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:23.967626 16742 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/instance:
uuid: "63d93859de504a01a06a9c15e3c8f1b6"
format_stamp: "Formatted at 2026-08-12 06:20:23 on dist-test-slave-8n49"
I20260812 06:20:23.969197 16742 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:23.970165 16859 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:23.970472 16742 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:23.970574 16742 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root
uuid: "63d93859de504a01a06a9c15e3c8f1b6"
format_stamp: "Formatted at 2026-08-12 06:20:23 on dist-test-slave-8n49"
I20260812 06:20:23.970650 16742 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-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:24.008054 16742 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:24.008631 16742 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:24.009150 16742 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:24.010032 16742 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:24.010104 16742 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:24.010176 16742 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:24.010223 16742 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:24.017174 16742 rpc_server.cc:307] RPC server started. Bound to: 127.16.89.129:38543
I20260812 06:20:24.017243 16931 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.89.129:38543 every 8 connection(s)
I20260812 06:20:24.031103 16932 heartbeater.cc:344] Connected to a master server at 127.16.89.190:35669
I20260812 06:20:24.031405 16932 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:24.031955 16932 heartbeater.cc:507] Master 127.16.89.190:35669 requested a full tablet report, sending...
I20260812 06:20:24.033504 16773 ts_manager.cc:194] Registered new tserver with Master: 63d93859de504a01a06a9c15e3c8f1b6 (127.16.89.129:38543)
I20260812 06:20:24.033659 16742 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015832443s
I20260812 06:20:24.035043 16773 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45688
I20260812 06:20:24.043454 16773 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45696:
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:24.058301 16890 tablet_service.cc:1511] Processing CreateTablet for tablet 4d808b5c81e54b648df8f7055934797e (DEFAULT_TABLE table=heavy-update-compaction-test [id=08c37a4139184b8ca23ffac5d0df963d]), partition=
I20260812 06:20:24.058825 16890 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 4d808b5c81e54b648df8f7055934797e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:24.061750 16945 tablet_bootstrap.cc:492] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Bootstrap starting.
I20260812 06:20:24.062952 16945 tablet_bootstrap.cc:654] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:24.064159 16945 tablet_bootstrap.cc:492] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: No bootstrap required, opened a new log
I20260812 06:20:24.064280 16945 ts_tablet_manager.cc:1403] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:24.064808 16945 raft_consensus.cc:359] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "63d93859de504a01a06a9c15e3c8f1b6" member_type: VOTER last_known_addr { host: "127.16.89.129" port: 38543 } }
I20260812 06:20:24.064929 16945 raft_consensus.cc:385] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:24.064999 16945 raft_consensus.cc:740] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 63d93859de504a01a06a9c15e3c8f1b6, State: Initialized, Role: FOLLOWER
I20260812 06:20:24.065186 16945 consensus_queue.cc:260] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6 [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: "63d93859de504a01a06a9c15e3c8f1b6" member_type: VOTER last_known_addr { host: "127.16.89.129" port: 38543 } }
I20260812 06:20:24.065320 16945 raft_consensus.cc:399] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:24.065378 16945 raft_consensus.cc:493] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:24.065455 16945 raft_consensus.cc:3060] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:24.066274 16945 raft_consensus.cc:515] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "63d93859de504a01a06a9c15e3c8f1b6" member_type: VOTER last_known_addr { host: "127.16.89.129" port: 38543 } }
I20260812 06:20:24.066385 16945 leader_election.cc:304] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6 [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: 63d93859de504a01a06a9c15e3c8f1b6; no voters: 
I20260812 06:20:24.066617 16945 leader_election.cc:290] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:24.066717 16947 raft_consensus.cc:2804] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:24.066897 16947 raft_consensus.cc:697] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6 [term 1 LEADER]: Becoming Leader. State: Replica: 63d93859de504a01a06a9c15e3c8f1b6, State: Running, Role: LEADER
I20260812 06:20:24.067013 16945 ts_tablet_manager.cc:1434] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:24.067103 16947 consensus_queue.cc:237] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6 [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: "63d93859de504a01a06a9c15e3c8f1b6" member_type: VOTER last_known_addr { host: "127.16.89.129" port: 38543 } }
I20260812 06:20:24.067337 16932 heartbeater.cc:499] Master 127.16.89.190:35669 was elected leader, sending a full tablet report...
I20260812 06:20:24.069890 16773 catalog_manager.cc:5719] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6 reported cstate change: term changed from 0 to 1, leader changed from <none> to 63d93859de504a01a06a9c15e3c8f1b6 (127.16.89.129). New cstate: current_term: 1 leader_uuid: "63d93859de504a01a06a9c15e3c8f1b6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "63d93859de504a01a06a9c15e3c8f1b6" member_type: VOTER last_known_addr { host: "127.16.89.129" port: 38543 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:24.132913 16742 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.025s	sys 0.000s
I20260812 06:20:24.268261 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushMRSOp(4d808b5c81e54b648df8f7055934797e): perf score=19.054940
I20260812 06:20:24.462517 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushMRSOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.194s	user 0.157s	sys 0.032s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":283,"delete_count":0,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":1019,"drs_written":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4,"lbm_write_time_us":49813,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":158,"threads_started":1,"update_count":1500}
I20260812 06:20:24.463852 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling LogGCOp(4d808b5c81e54b648df8f7055934797e): free 20743880 bytes of WAL
I20260812 06:20:24.464166 16865 log_reader.cc:385] T 4d808b5c81e54b648df8f7055934797e: removed 2 log segments from log reader
I20260812 06:20:24.464231 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000001 (ops 1-6)
I20260812 06:20:24.464290 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000002 (ops 7-11)
I20260812 06:20:24.470029 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: LogGCOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:20:24.470419 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:24.486753 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.016s	user 0.011s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5660,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.487334 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:24.631409 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.144s	user 0.117s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":498,"lbm_read_time_us":8294,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22773,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":363,"threads_started":5,"update_count":2000}
I20260812 06:20:24.632022 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling UndoDeltaBlockGCOp(4d808b5c81e54b648df8f7055934797e): 16411393 bytes on disk
I20260812 06:20:24.632687 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: UndoDeltaBlockGCOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":90,"lbm_reads_lt_1ms":4}
I20260812 06:20:24.633314 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=10.126437
I20260812 06:20:24.679005 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.046s	user 0.027s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17449,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:24.679553 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:24.692490 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.692994 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:24.813447 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.120s	user 0.104s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":211,"lbm_read_time_us":9097,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23250,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":43008,"update_count":2000}
I20260812 06:20:24.814057 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=10.126437
I20260812 06:20:24.855394 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.041s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19052,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:24.855952 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:24.873008 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.017s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5295,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.873579 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:24.990792 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.117s	user 0.084s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":324,"lbm_read_time_us":7063,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23768,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2000}
I20260812 06:20:24.991731 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=10.126437
I20260812 06:20:25.034998 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.043s	user 0.018s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16305,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.035591 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:25.046507 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4147,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.046984 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:25.206231 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.159s	user 0.113s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":288,"lbm_read_time_us":12052,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26620,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2000}
I20260812 06:20:25.206835 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=10.126437
I20260812 06:20:25.257174 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.050s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16861,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.257678 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:25.268857 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4037,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.269367 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:25.392436 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.123s	user 0.090s	sys 0.032s 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":61,"lbm_read_time_us":8619,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22664,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2000}
I20260812 06:20:25.393891 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=10.126437
I20260812 06:20:25.435719 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.042s	user 0.036s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18593,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.436254 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:25.447932 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4302,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.448437 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:25.574826 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.126s	user 0.080s	sys 0.044s 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":89,"lbm_read_time_us":9329,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23625,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:20:25.575611 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=10.126437
I20260812 06:20:25.622095 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.046s	user 0.025s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16208,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.622521 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:25.633091 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4116,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.633562 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushMRSOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:25.666040 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushMRSOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.032s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":259,"dirs.run_wall_time_us":1352,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1614,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:25.667156 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling LogGCOp(4d808b5c81e54b648df8f7055934797e): free 112239310 bytes of WAL
I20260812 06:20:25.667410 16865 log_reader.cc:385] T 4d808b5c81e54b648df8f7055934797e: removed 11 log segments from log reader
I20260812 06:20:25.667456 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000003 (ops 12-16)
I20260812 06:20:25.667512 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000004 (ops 17-21)
I20260812 06:20:25.667562 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000005 (ops 22-26)
I20260812 06:20:25.667605 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000006 (ops 27-30)
I20260812 06:20:25.667647 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000007 (ops 31-35)
I20260812 06:20:25.667690 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000008 (ops 36-40)
I20260812 06:20:25.667732 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000009 (ops 41-45)
I20260812 06:20:25.667773 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000010 (ops 46-50)
I20260812 06:20:25.667816 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000011 (ops 51-55)
I20260812 06:20:25.667857 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000012 (ops 56-60)
I20260812 06:20:25.667898 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000013 (ops 61-65)
I20260812 06:20:25.693991 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: LogGCOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:25.694407 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:25.711315 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.017s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4850,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.711753 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling UndoDeltaBlockGCOp(4d808b5c81e54b648df8f7055934797e): 447 bytes on disk
I20260812 06:20:25.712163 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: UndoDeltaBlockGCOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.712720 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:25.724123 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4142,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.724838 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:25.910547 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.186s	user 0.147s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":752,"lbm_read_time_us":13054,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36975,"lbm_writes_lt_1ms":643,"mutex_wait_us":338,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:20:25.911194 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=14.095187
I20260812 06:20:25.960172 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.049s	user 0.025s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20575,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.960721 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:25.976267 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6017,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.976781 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:26.131422 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.154s	user 0.126s	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":762,"lbm_read_time_us":9291,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30280,"lbm_writes_lt_1ms":543,"mutex_wait_us":324,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":26752,"update_count":2500}
I20260812 06:20:26.132129 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=12.110812
I20260812 06:20:26.178452 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.046s	user 0.028s	sys 0.015s Metrics: {"bytes_written":13784349,"delete_count":0,"lbm_write_time_us":21786,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":337,"reinsert_count":0,"update_count":1680}
I20260812 06:20:26.178922 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=1.196750
I20260812 06:20:26.198366 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.019s	user 0.000s	sys 0.006s Metrics: {"bytes_written":2625754,"delete_count":0,"lbm_write_time_us":2778,"lbm_writes_lt_1ms":67,"reinsert_count":0,"update_count":320}
I20260812 06:20:26.198805 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:26.209299 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3937,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.209760 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:26.401227 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.191s	user 0.123s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774762,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":537,"lbm_read_time_us":10495,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32893,"lbm_writes_lt_1ms":543,"mutex_wait_us":253,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2500}
I20260812 06:20:26.401914 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=14.095187
I20260812 06:20:26.465138 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.061s	user 0.038s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25922,"lbm_writes_lt_1ms":403,"mutex_wait_us":34,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.465692 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:26.476457 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3999,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.476969 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:26.653800 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.177s	user 0.129s	sys 0.044s 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":1039,"lbm_read_time_us":12841,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32957,"lbm_writes_lt_1ms":543,"mutex_wait_us":312,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:20:26.654385 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=14.095187
I20260812 06:20:26.716006 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.061s	user 0.033s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21232,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.716663 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:26.727154 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4151,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.727587 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:26.892998 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.165s	user 0.137s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":431,"lbm_read_time_us":12451,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27152,"lbm_writes_lt_1ms":543,"mutex_wait_us":109,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2500}
I20260812 06:20:26.896903 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=10.126437
I20260812 06:20:26.931337 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.034s	user 0.015s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14848,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.931951 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:26.949374 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6652,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.949954 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:27.104863 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.155s	user 0.112s	sys 0.042s 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":284,"lbm_read_time_us":8023,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26871,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:20:27.105669 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=10.126437
I20260812 06:20:27.144688 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.039s	user 0.034s	sys 0.005s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17070,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:27.145151 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:27.156257 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4119,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.157020 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushMRSOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:27.183218 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushMRSOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.026s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":1715,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1477,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":93440}
I20260812 06:20:27.183983 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling LogGCOp(4d808b5c81e54b648df8f7055934797e): free 124710254 bytes of WAL
I20260812 06:20:27.184252 16865 log_reader.cc:385] T 4d808b5c81e54b648df8f7055934797e: removed 12 log segments from log reader
I20260812 06:20:27.184314 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000014 (ops 66-70)
I20260812 06:20:27.184351 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000015 (ops 71-75)
I20260812 06:20:27.184387 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000016 (ops 76-80)
I20260812 06:20:27.184414 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000017 (ops 81-85)
I20260812 06:20:27.184445 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000018 (ops 86-91)
I20260812 06:20:27.184475 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000019 (ops 92-96)
I20260812 06:20:27.184504 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000020 (ops 97-101)
I20260812 06:20:27.184532 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000021 (ops 102-106)
I20260812 06:20:27.184595 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000022 (ops 107-110)
I20260812 06:20:27.184629 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000023 (ops 111-115)
I20260812 06:20:27.184657 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000024 (ops 116-120)
I20260812 06:20:27.184687 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000025 (ops 121-125)
I20260812 06:20:27.212828 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: LogGCOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.029s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:20:27.213305 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:27.237648 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.024s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5366,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.238106 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling UndoDeltaBlockGCOp(4d808b5c81e54b648df8f7055934797e): 471 bytes on disk
I20260812 06:20:27.238503 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: UndoDeltaBlockGCOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:20:27.238977 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:27.249475 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.010s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4047,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.250242 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:27.433539 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.183s	user 0.142s	sys 0.038s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":460,"lbm_read_time_us":12160,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36763,"lbm_writes_lt_1ms":643,"mutex_wait_us":57,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:20:27.434305 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=14.095187
I20260812 06:20:27.482969 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.047s	user 0.024s	sys 0.015s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":18666,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.483501 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:27.494144 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4068,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.494660 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:27.685513 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.191s	user 0.147s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":198,"lbm_read_time_us":10375,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30492,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:20:27.686221 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=14.095187
I20260812 06:20:27.740711 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.054s	user 0.039s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18996,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.741240 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:27.753763 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4371,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.754470 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:27.901594 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.147s	user 0.119s	sys 0.028s 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":202,"lbm_read_time_us":9695,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30709,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27008,"update_count":2500}
I20260812 06:20:27.902105 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=10.126437
I20260812 06:20:27.936160 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.034s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12389539,"delete_count":0,"lbm_write_time_us":14608,"lbm_writes_lt_1ms":305,"reinsert_count":0,"update_count":1510}
I20260812 06:20:27.936731 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:27.952073 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4020609,"delete_count":0,"lbm_write_time_us":5677,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:20:27.952767 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:28.089660 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.137s	user 0.107s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":105,"lbm_read_time_us":8722,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27512,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:20:28.090678 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=10.126437
I20260812 06:20:28.130961 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.040s	user 0.012s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15176,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:28.131537 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:28.144381 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.013s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4551,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.144936 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:28.284775 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.140s	user 0.124s	sys 0.016s 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":381,"lbm_read_time_us":9484,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27855,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:20:28.285349 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=10.126437
I20260812 06:20:28.327770 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.042s	user 0.028s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14610,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:28.328362 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:28.343776 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.015s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4652,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.344522 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:28.497798 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.153s	user 0.128s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":183,"lbm_read_time_us":11121,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25147,"lbm_writes_lt_1ms":443,"mutex_wait_us":69,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:28.498492 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=10.126437
I20260812 06:20:28.544340 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.046s	user 0.035s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20138,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:28.544902 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:28.561090 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6199,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.561661 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushMRSOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:28.588233 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushMRSOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.026s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":178,"dirs.run_wall_time_us":1250,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1787,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:28.588977 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling LogGCOp(4d808b5c81e54b648df8f7055934797e): free 115943468 bytes of WAL
I20260812 06:20:28.589238 16865 log_reader.cc:385] T 4d808b5c81e54b648df8f7055934797e: removed 11 log segments from log reader
I20260812 06:20:28.589301 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000026 (ops 126-130)
I20260812 06:20:28.589340 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000027 (ops 131-135)
I20260812 06:20:28.589371 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000028 (ops 136-140)
I20260812 06:20:28.589394 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000029 (ops 141-145)
I20260812 06:20:28.589425 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000030 (ops 146-150)
I20260812 06:20:28.589460 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000031 (ops 151-155)
I20260812 06:20:28.589490 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000032 (ops 156-160)
I20260812 06:20:28.589520 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000033 (ops 161-165)
I20260812 06:20:28.589569 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000034 (ops 166-170)
I20260812 06:20:28.589627 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000035 (ops 171-175)
I20260812 06:20:28.589661 16865 log.cc:1079] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/4d808b5c81e54b648df8f7055934797e/wal-000000036 (ops 176-180)
I20260812 06:20:28.618086 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: LogGCOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:28.618558 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:28.641693 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.023s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5344,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.642143 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:28.660952 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.019s	user 0.011s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3797,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.661510 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling UndoDeltaBlockGCOp(4d808b5c81e54b648df8f7055934797e): 447 bytes on disk
I20260812 06:20:28.662006 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: UndoDeltaBlockGCOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:20:28.662523 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:28.866907 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.204s	user 0.136s	sys 0.067s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":461,"lbm_read_time_us":15747,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33311,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8320,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:20:28.867600 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=14.095187
I20260812 06:20:28.924621 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.057s	user 0.040s	sys 0.015s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":20193,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.925212 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=2.188937
I20260812 06:20:28.936959 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4443,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.937428 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:29.092149 16742 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.959s	user 1.835s	sys 0.142s
I20260812 06:20:29.118351 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.181s	user 0.119s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":13038,"lbm_reads_lt_1ms":568,"lbm_write_time_us":33006,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:29.118837 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e): perf score=10.126437
I20260812 06:20:29.146441 16742 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.054s	user 0.002s	sys 0.000s
I20260812 06:20:29.147043 16742 tablet_server.cc:179] TabletServer@127.16.89.129:0 shutting down...
I20260812 06:20:29.149421 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: FlushDeltaMemStoresOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.030s	user 0.016s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13134,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:29.149914 16933 maintenance_manager.cc:419] P 63d93859de504a01a06a9c15e3c8f1b6: Scheduling MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e): perf score=1.000000
I20260812 06:20:29.255970 16865 maintenance_manager.cc:643] P 63d93859de504a01a06a9c15e3c8f1b6: MajorDeltaCompactionOp(4d808b5c81e54b648df8f7055934797e) complete. Timing: real 0.106s	user 0.073s	sys 0.032s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":194,"lbm_read_time_us":6107,"lbm_reads_lt_1ms":367,"lbm_write_time_us":21085,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":342,"mutex_wait_us":48,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":38528,"update_count":1500}
I20260812 06:20:29.258430 16742 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:29.258879 16742 tablet_replica.cc:333] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6: stopping tablet replica
I20260812 06:20:29.259155 16742 raft_consensus.cc:2243] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:29.259449 16742 raft_consensus.cc:2272] T 4d808b5c81e54b648df8f7055934797e P 63d93859de504a01a06a9c15e3c8f1b6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:29.275466 16742 tablet_server.cc:196] TabletServer@127.16.89.129:0 shutdown complete.
I20260812 06:20:29.289126 16742 master.cc:562] Master@127.16.89.190:35669 shutting down...
I20260812 06:20:29.292716 16742 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:29.292892 16742 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:29.292984 16742 tablet_replica.cc:333] T 00000000000000000000000000000000 P 8872b7e85adf490992e804a084c11bb9: stopping tablet replica
I20260812 06:20:29.305320 16742 master.cc:584] Master@127.16.89.190:35669 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5582 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:29.398208 16742 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.16.89.190:33641
I20260812 06:20:29.398623 16742 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:29.400792 16968 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:29.400810 16969 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:29.400954 16972 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:29.401031 16742 server_base.cc:1061] running on GCE node
I20260812 06:20:29.401279 16742 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:29.401319 16742 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:29.401335 16742 hybrid_clock.cc:648] HybridClock initialized: now 1786515629401335 us; error 0 us; skew 500 ppm
I20260812 06:20:29.402233 16742 webserver.cc:533] Webserver started at http://127.16.89.190:41437/ using document root <none> and password file <none>
I20260812 06:20:29.402371 16742 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:29.402424 16742 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:29.402477 16742 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:29.402822 16742 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/master-0-root/instance:
uuid: "0c966c8751644d16a89c9bee9253e5f0"
format_stamp: "Formatted at 2026-08-12 06:20:29 on dist-test-slave-8n49"
I20260812 06:20:29.404289 16742 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:29.405432 16977 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:29.405718 16742 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:29.405790 16742 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/master-0-root
uuid: "0c966c8751644d16a89c9bee9253e5f0"
format_stamp: "Formatted at 2026-08-12 06:20:29 on dist-test-slave-8n49"
I20260812 06:20:29.405884 16742 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-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:29.413296 16742 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:29.413672 16742 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:29.417870 16742 rpc_server.cc:307] RPC server started. Bound to: 127.16.89.190:33641
I20260812 06:20:29.420011 17038 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.89.190:33641 every 8 connection(s)
I20260812 06:20:29.422382 17039 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:29.429447 17039 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0: Bootstrap starting.
I20260812 06:20:29.430660 17039 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:29.431969 17039 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0: No bootstrap required, opened a new log
I20260812 06:20:29.432592 17039 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0c966c8751644d16a89c9bee9253e5f0" member_type: VOTER }
I20260812 06:20:29.432726 17039 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:29.432776 17039 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0c966c8751644d16a89c9bee9253e5f0, State: Initialized, Role: FOLLOWER
I20260812 06:20:29.432931 17039 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [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: "0c966c8751644d16a89c9bee9253e5f0" member_type: VOTER }
I20260812 06:20:29.433023 17039 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:29.433066 17039 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:29.433120 17039 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:29.433975 17039 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0c966c8751644d16a89c9bee9253e5f0" member_type: VOTER }
I20260812 06:20:29.434137 17039 leader_election.cc:304] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [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: 0c966c8751644d16a89c9bee9253e5f0; no voters: 
I20260812 06:20:29.434332 17039 leader_election.cc:290] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:29.434446 17043 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:29.434667 17043 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [term 1 LEADER]: Becoming Leader. State: Replica: 0c966c8751644d16a89c9bee9253e5f0, State: Running, Role: LEADER
I20260812 06:20:29.434803 17043 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [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: "0c966c8751644d16a89c9bee9253e5f0" member_type: VOTER }
I20260812 06:20:29.434875 17039 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:29.435231 17044 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0c966c8751644d16a89c9bee9253e5f0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0c966c8751644d16a89c9bee9253e5f0" member_type: VOTER } }
I20260812 06:20:29.435492 17044 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:29.435405 17045 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0c966c8751644d16a89c9bee9253e5f0. Latest consensus state: current_term: 1 leader_uuid: "0c966c8751644d16a89c9bee9253e5f0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0c966c8751644d16a89c9bee9253e5f0" member_type: VOTER } }
I20260812 06:20:29.435797 17045 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:29.436008 17049 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:29.437023 17049 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:29.437218 16742 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:29.438967 17049 catalog_manager.cc:1383] Generated new cluster ID: afb6ad03138c492abe8d833b432013bc
I20260812 06:20:29.439036 17049 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:29.456012 17049 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:29.456677 17049 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:29.465083 17049 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0: Generated new TSK 0
I20260812 06:20:29.465288 17049 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:29.469995 16742 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:20:29.472179 16742 server_base.cc:1061] running on GCE node
W20260812 06:20:29.472141 17063 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:29.472148 17068 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:29.472295 17066 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:29.472692 16742 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:29.472741 16742 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:29.472759 16742 hybrid_clock.cc:648] HybridClock initialized: now 1786515629472760 us; error 0 us; skew 500 ppm
I20260812 06:20:29.473626 16742 webserver.cc:533] Webserver started at http://127.16.89.129:42031/ using document root <none> and password file <none>
I20260812 06:20:29.473766 16742 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:29.473811 16742 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:29.473869 16742 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:29.474224 16742 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/instance:
uuid: "89c8cfcb01004ac397c5261b866f8d5a"
format_stamp: "Formatted at 2026-08-12 06:20:29 on dist-test-slave-8n49"
I20260812 06:20:29.475672 16742 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:29.476739 17073 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:29.477010 16742 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:29.477082 16742 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root
uuid: "89c8cfcb01004ac397c5261b866f8d5a"
format_stamp: "Formatted at 2026-08-12 06:20:29 on dist-test-slave-8n49"
I20260812 06:20:29.477174 16742 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-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:29.497314 16742 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:29.497752 16742 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:29.498085 16742 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:29.498572 16742 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:29.498639 16742 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:29.498690 16742 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:29.498735 16742 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:29.502882 16742 rpc_server.cc:307] RPC server started. Bound to: 127.16.89.129:36041
I20260812 06:20:29.503813 17151 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.89.129:36041 every 8 connection(s)
I20260812 06:20:29.508420 17152 heartbeater.cc:344] Connected to a master server at 127.16.89.190:33641
I20260812 06:20:29.508543 17152 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:29.508812 17152 heartbeater.cc:507] Master 127.16.89.190:33641 requested a full tablet report, sending...
I20260812 06:20:29.509485 16994 ts_manager.cc:194] Registered new tserver with Master: 89c8cfcb01004ac397c5261b866f8d5a (127.16.89.129:36041)
I20260812 06:20:29.510249 16742 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.006641114s
I20260812 06:20:29.510296 16994 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55790
I20260812 06:20:29.517560 16994 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55794:
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:29.526476 17107 tablet_service.cc:1511] Processing CreateTablet for tablet 80567b4f3e0b46a3b2854e594739f9f7 (DEFAULT_TABLE table=heavy-update-compaction-test [id=fa5e850cb720466e81c1269a5e6a3c97]), partition=
I20260812 06:20:29.526808 17107 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 80567b4f3e0b46a3b2854e594739f9f7. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:29.528930 17165 tablet_bootstrap.cc:492] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Bootstrap starting.
I20260812 06:20:29.529879 17165 tablet_bootstrap.cc:654] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:29.530972 17165 tablet_bootstrap.cc:492] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: No bootstrap required, opened a new log
I20260812 06:20:29.531071 17165 ts_tablet_manager.cc:1403] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:29.531548 17165 raft_consensus.cc:359] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "89c8cfcb01004ac397c5261b866f8d5a" member_type: VOTER last_known_addr { host: "127.16.89.129" port: 36041 } }
I20260812 06:20:29.531641 17165 raft_consensus.cc:385] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:29.531704 17165 raft_consensus.cc:740] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 89c8cfcb01004ac397c5261b866f8d5a, State: Initialized, Role: FOLLOWER
I20260812 06:20:29.531888 17165 consensus_queue.cc:260] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a [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: "89c8cfcb01004ac397c5261b866f8d5a" member_type: VOTER last_known_addr { host: "127.16.89.129" port: 36041 } }
I20260812 06:20:29.532012 17165 raft_consensus.cc:399] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:29.532063 17165 raft_consensus.cc:493] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:29.532125 17165 raft_consensus.cc:3060] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:29.533073 17165 raft_consensus.cc:515] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "89c8cfcb01004ac397c5261b866f8d5a" member_type: VOTER last_known_addr { host: "127.16.89.129" port: 36041 } }
I20260812 06:20:29.533226 17165 leader_election.cc:304] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a [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: 89c8cfcb01004ac397c5261b866f8d5a; no voters: 
I20260812 06:20:29.533463 17165 leader_election.cc:290] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:29.533627 17167 raft_consensus.cc:2804] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:29.533845 17167 raft_consensus.cc:697] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a [term 1 LEADER]: Becoming Leader. State: Replica: 89c8cfcb01004ac397c5261b866f8d5a, State: Running, Role: LEADER
I20260812 06:20:29.533869 17165 ts_tablet_manager.cc:1434] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:29.533878 17152 heartbeater.cc:499] Master 127.16.89.190:33641 was elected leader, sending a full tablet report...
I20260812 06:20:29.534011 17167 consensus_queue.cc:237] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a [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: "89c8cfcb01004ac397c5261b866f8d5a" member_type: VOTER last_known_addr { host: "127.16.89.129" port: 36041 } }
I20260812 06:20:29.535362 16994 catalog_manager.cc:5719] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a reported cstate change: term changed from 0 to 1, leader changed from <none> to 89c8cfcb01004ac397c5261b866f8d5a (127.16.89.129). New cstate: current_term: 1 leader_uuid: "89c8cfcb01004ac397c5261b866f8d5a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "89c8cfcb01004ac397c5261b866f8d5a" member_type: VOTER last_known_addr { host: "127.16.89.129" port: 36041 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:29.596100 16742 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.012s	sys 0.012s
I20260812 06:20:29.754321 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushMRSOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=19.054940
I20260812 06:20:29.901472 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushMRSOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.147s	user 0.102s	sys 0.044s Metrics: {"bytes_written":12717740,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":192,"dirs.run_wall_time_us":884,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37703,"lbm_writes_lt_1ms":777,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":2944,"update_count":1550}
I20260812 06:20:29.902087 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling LogGCOp(80567b4f3e0b46a3b2854e594739f9f7): free 20290830 bytes of WAL
I20260812 06:20:29.902309 17080 log_reader.cc:385] T 80567b4f3e0b46a3b2854e594739f9f7: removed 2 log segments from log reader
I20260812 06:20:29.902366 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000001 (ops 1-6)
I20260812 06:20:29.902443 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000002 (ops 7-10)
I20260812 06:20:29.907433 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: LogGCOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:29.907809 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:29.919327 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692409,"delete_count":0,"lbm_write_time_us":3896,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:29.919809 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling UndoDeltaBlockGCOp(80567b4f3e0b46a3b2854e594739f9f7): 16821646 bytes on disk
I20260812 06:20:29.920413 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: UndoDeltaBlockGCOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":90,"lbm_reads_lt_1ms":4}
I20260812 06:20:29.920853 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:30.069669 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.149s	user 0.102s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":503,"lbm_read_time_us":10609,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25257,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":304,"threads_started":5,"update_count":2000}
I20260812 06:20:30.070469 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=10.126437
I20260812 06:20:30.108109 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.037s	user 0.024s	sys 0.010s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17498,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:30.108681 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:30.119016 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3888,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:30.119599 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:30.268184 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.148s	user 0.104s	sys 0.044s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20303019,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":727,"lbm_read_time_us":11269,"lbm_reads_lt_1ms":462,"lbm_write_time_us":23644,"lbm_writes_lt_1ms":433,"mutex_wait_us":314,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1950}
I20260812 06:20:30.269037 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=11.118625
I20260812 06:20:30.310788 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.042s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16103,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:30.311448 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:30.336686 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.025s	user 0.012s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5490,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:30.337194 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:30.347363 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.010s	user 0.003s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3876,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.347846 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:30.534662 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.187s	user 0.138s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":230,"lbm_read_time_us":10622,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28516,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2500}
I20260812 06:20:30.535279 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=14.095187
I20260812 06:20:30.587944 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.052s	user 0.035s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21841,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.588434 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:30.601213 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4385,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.601847 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:30.778239 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.176s	user 0.148s	sys 0.022s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":242,"lbm_read_time_us":10906,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34369,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2500}
I20260812 06:20:30.778743 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=14.095187
I20260812 06:20:30.830214 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.051s	user 0.033s	sys 0.009s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18873,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.830750 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:30.846927 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5937,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.847484 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:31.000461 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.153s	user 0.110s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":263,"lbm_read_time_us":9785,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32335,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":64896,"update_count":2500}
I20260812 06:20:31.001395 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=11.118625
I20260812 06:20:31.041433 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.040s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16065,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:31.041970 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:31.059325 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.017s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4211,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.059854 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:31.069465 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3507,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:31.069926 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:31.221076 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.151s	user 0.116s	sys 0.034s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":449,"lbm_read_time_us":12795,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28418,"lbm_writes_lt_1ms":543,"mutex_wait_us":89,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:20:31.222021 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=11.118625
I20260812 06:20:31.262708 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.040s	user 0.013s	sys 0.026s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18335,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:31.263192 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:31.279101 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.016s	user 0.000s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5336,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:31.279527 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushMRSOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:31.306293 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushMRSOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.027s	user 0.022s	sys 0.003s Metrics: {"bytes_written":1316413,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":1296,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1584,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":1920}
I20260812 06:20:31.306874 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling LogGCOp(80567b4f3e0b46a3b2854e594739f9f7): free 125616638 bytes of WAL
I20260812 06:20:31.307192 17080 log_reader.cc:385] T 80567b4f3e0b46a3b2854e594739f9f7: removed 13 log segments from log reader
I20260812 06:20:31.307246 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000003 (ops 11-15)
I20260812 06:20:31.307300 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000004 (ops 16-20)
I20260812 06:20:31.307358 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000005 (ops 21-24)
I20260812 06:20:31.307400 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000006 (ops 25-29)
I20260812 06:20:31.307436 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000007 (ops 30-34)
I20260812 06:20:31.307472 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000008 (ops 35-38)
I20260812 06:20:31.307508 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000009 (ops 39-43)
I20260812 06:20:31.307545 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000010 (ops 44-48)
I20260812 06:20:31.307581 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000011 (ops 49-53)
I20260812 06:20:31.307618 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000012 (ops 54-58)
I20260812 06:20:31.307684 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000013 (ops 59-62)
I20260812 06:20:31.307726 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000014 (ops 63-67)
I20260812 06:20:31.307771 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000015 (ops 68-72)
I20260812 06:20:31.334095 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: LogGCOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:31.334546 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=6.157687
I20260812 06:20:31.356276 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.022s	user 0.011s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9066,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:31.356750 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling LogGCOp(80567b4f3e0b46a3b2854e594739f9f7): free 12017927 bytes of WAL
I20260812 06:20:31.356948 17080 log_reader.cc:385] T 80567b4f3e0b46a3b2854e594739f9f7: removed 1 log segments from log reader
I20260812 06:20:31.357004 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000016 (ops 73-77)
I20260812 06:20:31.359447 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: LogGCOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:31.359771 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling UndoDeltaBlockGCOp(80567b4f3e0b46a3b2854e594739f9f7): 493 bytes on disk
I20260812 06:20:31.360138 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: UndoDeltaBlockGCOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:20:31.360620 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:31.528689 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.168s	user 0.134s	sys 0.033s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918208,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":618,"lbm_read_time_us":12176,"lbm_reads_lt_1ms":665,"lbm_write_time_us":32389,"lbm_writes_lt_1ms":643,"mutex_wait_us":36,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17920,"thread_start_us":141,"threads_started":1,"update_count":3000}
I20260812 06:20:31.529341 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=14.095187
I20260812 06:20:31.577256 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.048s	user 0.029s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20616,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.578190 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:31.605775 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.027s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5926,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.606202 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:31.616879 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4009,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.617462 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:31.784133 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.166s	user 0.126s	sys 0.040s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918212,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":181,"lbm_read_time_us":13728,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32319,"lbm_writes_lt_1ms":643,"mutex_wait_us":29,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":3000}
I20260812 06:20:31.784927 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=14.095187
I20260812 06:20:31.830554 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.045s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19797,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.831141 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:31.846899 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.016s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6288,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.847437 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:32.026530 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.179s	user 0.131s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":345,"lbm_read_time_us":10977,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31778,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2500}
I20260812 06:20:32.027330 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=14.095187
I20260812 06:20:32.074831 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.047s	user 0.022s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19534,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.075407 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:32.233161 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.158s	user 0.101s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713154,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":154,"lbm_read_time_us":10225,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25832,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:20:32.233920 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=14.095187
I20260812 06:20:32.284622 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.050s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18366,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.285133 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:32.296761 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4219,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.297216 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:32.491725 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.194s	user 0.135s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":612,"lbm_read_time_us":11511,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30568,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":2500}
I20260812 06:20:32.492479 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=14.095187
I20260812 06:20:32.549273 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.057s	user 0.035s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23528,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.549815 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:32.561748 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4490,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.562207 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:32.722954 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.161s	user 0.130s	sys 0.030s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":338,"lbm_read_time_us":9121,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30499,"lbm_writes_lt_1ms":543,"mutex_wait_us":64,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":57344,"update_count":2500}
I20260812 06:20:32.723677 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=14.095187
I20260812 06:20:32.776264 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.052s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":23722,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.776834 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:32.789479 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4806,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.790024 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushMRSOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:32.817535 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushMRSOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.027s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1275446,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":1528,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1636,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:32.818163 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling LogGCOp(80567b4f3e0b46a3b2854e594739f9f7): free 124257280 bytes of WAL
I20260812 06:20:32.818385 17080 log_reader.cc:385] T 80567b4f3e0b46a3b2854e594739f9f7: removed 12 log segments from log reader
I20260812 06:20:32.818427 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000017 (ops 78-82)
I20260812 06:20:32.818455 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000018 (ops 83-87)
I20260812 06:20:32.818514 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000019 (ops 88-92)
I20260812 06:20:32.818557 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000020 (ops 93-97)
I20260812 06:20:32.818600 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000021 (ops 98-102)
I20260812 06:20:32.818655 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000022 (ops 103-107)
I20260812 06:20:32.818691 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000023 (ops 108-112)
I20260812 06:20:32.818730 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000024 (ops 113-116)
I20260812 06:20:32.818768 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000025 (ops 117-121)
I20260812 06:20:32.818804 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000026 (ops 122-126)
I20260812 06:20:32.818841 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000027 (ops 127-131)
I20260812 06:20:32.818881 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000028 (ops 132-136)
I20260812 06:20:32.844523 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: LogGCOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.026s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:32.845078 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=4.173312
I20260812 06:20:32.869016 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.024s	user 0.013s	sys 0.010s Metrics: {"bytes_written":6276942,"delete_count":0,"lbm_write_time_us":6116,"lbm_writes_lt_1ms":156,"mutex_wait_us":50,"reinsert_count":0,"update_count":765}
I20260812 06:20:32.869526 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:32.875612 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.006s	user 0.004s	sys 0.000s Metrics: {"bytes_written":1928327,"delete_count":0,"lbm_write_time_us":1889,"lbm_writes_lt_1ms":50,"reinsert_count":0,"update_count":235}
I20260812 06:20:32.876024 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling UndoDeltaBlockGCOp(80567b4f3e0b46a3b2854e594739f9f7): 482 bytes on disk
I20260812 06:20:32.876403 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: UndoDeltaBlockGCOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:20:32.876883 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:33.133713 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.257s	user 0.154s	sys 0.091s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":663,"lbm_read_time_us":16415,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40650,"lbm_writes_lt_1ms":743,"mutex_wait_us":37,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1228928,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:20:33.134325 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=18.063937
I20260812 06:20:33.203609 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.069s	user 0.037s	sys 0.026s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":29341,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:33.204092 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:33.214851 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4147,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.215499 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:33.422392 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.207s	user 0.123s	sys 0.084s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":994,"lbm_read_time_us":13240,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33535,"lbm_writes_lt_1ms":643,"mutex_wait_us":268,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19456,"update_count":3000}
I20260812 06:20:33.422981 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=14.095187
I20260812 06:20:33.468436 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.045s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19670,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:33.469110 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:33.485651 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6674,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.486178 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:33.648916 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.162s	user 0.112s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":591,"lbm_read_time_us":11684,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26001,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":42240,"update_count":2500}
I20260812 06:20:33.649555 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=14.095187
I20260812 06:20:33.702618 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.053s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":23825,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:33.703220 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:33.720294 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6841,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.720834 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:33.899524 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.179s	user 0.132s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815681,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":160,"lbm_read_time_us":12959,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29875,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2500}
I20260812 06:20:33.900274 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=14.095187
I20260812 06:20:33.958590 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.058s	user 0.037s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20668,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:33.959400 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:33.971592 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4620,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.972066 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:34.157160 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.185s	user 0.106s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":231,"lbm_read_time_us":14036,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29379,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27008,"update_count":2500}
I20260812 06:20:34.157795 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=14.095187
I20260812 06:20:34.211851 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.054s	user 0.017s	sys 0.032s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22971,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:34.212426 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:34.238674 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.026s	user 0.016s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5726,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:34.239394 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushMRSOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:34.278303 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushMRSOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.039s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":1338,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1346,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:34.279068 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling LogGCOp(80567b4f3e0b46a3b2854e594739f9f7): free 120553644 bytes of WAL
I20260812 06:20:34.279326 17080 log_reader.cc:385] T 80567b4f3e0b46a3b2854e594739f9f7: removed 12 log segments from log reader
I20260812 06:20:34.279393 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000029 (ops 137-141)
I20260812 06:20:34.279443 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000030 (ops 142-146)
I20260812 06:20:34.279503 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000031 (ops 147-151)
I20260812 06:20:34.279546 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000032 (ops 152-156)
I20260812 06:20:34.279637 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000033 (ops 157-161)
I20260812 06:20:34.279708 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000034 (ops 162-166)
I20260812 06:20:34.279749 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000035 (ops 167-171)
I20260812 06:20:34.279778 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000036 (ops 172-176)
I20260812 06:20:34.279831 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000037 (ops 177-180)
I20260812 06:20:34.279868 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000038 (ops 181-185)
I20260812 06:20:34.279917 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000039 (ops 186-190)
I20260812 06:20:34.279958 17080 log.cc:1079] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: Deleting log segment in path: /tmp/dist-test-taskDTSies/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515623804814-16742-0/minicluster-data/ts-0-root/wals/80567b4f3e0b46a3b2854e594739f9f7/wal-000000040 (ops 191-194)
I20260812 06:20:34.304780 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: LogGCOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:34.305262 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling UndoDeltaBlockGCOp(80567b4f3e0b46a3b2854e594739f9f7): 448 bytes on disk
I20260812 06:20:34.305739 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: UndoDeltaBlockGCOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:20:34.306288 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=3.181125
I20260812 06:20:34.325958 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.019s	user 0.000s	sys 0.011s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4985,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:34.326457 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=2.188937
I20260812 06:20:34.338958 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: FlushDeltaMemStoresOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4795,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:34.339454 17153 maintenance_manager.cc:419] P 89c8cfcb01004ac397c5261b866f8d5a: Scheduling MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7): perf score=1.000000
I20260812 06:20:34.421772 16742 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.826s	user 1.865s	sys 0.136s
I20260812 06:20:34.521792 16742 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.100s	user 0.003s	sys 0.000s
I20260812 06:20:34.522362 16742 tablet_server.cc:179] TabletServer@127.16.89.129:0 shutting down...
I20260812 06:20:34.559407 17080 maintenance_manager.cc:643] P 89c8cfcb01004ac397c5261b866f8d5a: MajorDeltaCompactionOp(80567b4f3e0b46a3b2854e594739f9f7) complete. Timing: real 0.220s	user 0.131s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020734,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":646,"lbm_read_time_us":15230,"lbm_reads_lt_1ms":770,"lbm_write_time_us":33560,"lbm_writes_lt_1ms":743,"mutex_wait_us":41,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:20:34.560221 16742 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:34.560639 16742 tablet_replica.cc:333] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a: stopping tablet replica
I20260812 06:20:34.560804 16742 raft_consensus.cc:2243] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:34.560978 16742 raft_consensus.cc:2272] T 80567b4f3e0b46a3b2854e594739f9f7 P 89c8cfcb01004ac397c5261b866f8d5a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:34.567320 16742 tablet_server.cc:196] TabletServer@127.16.89.129:0 shutdown complete.
I20260812 06:20:34.619078 16742 master.cc:562] Master@127.16.89.190:33641 shutting down...
I20260812 06:20:34.622237 16742 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:34.622401 16742 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:34.622454 16742 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0c966c8751644d16a89c9bee9253e5f0: stopping tablet replica
I20260812 06:20:34.634850 16742 master.cc:584] Master@127.16.89.190:33641 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5327 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10910 ms total)

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