[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:27.266162 12864 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.144.62:45109
I20260812 06:18:27.267100 12864 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:27.267668 12864 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:27.274006 12864 server_base.cc:1061] running on GCE node
W20260812 06:18:27.273922 12874 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:27.273960 12875 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:27.274197 12878 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:27.274659 12864 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:27.274753 12864 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:27.274796 12864 hybrid_clock.cc:648] HybridClock initialized: now 1786515507274793 us; error 0 us; skew 500 ppm
I20260812 06:18:27.276415 12864 webserver.cc:533] Webserver started at http://127.12.144.62:41651/ using document root <none> and password file <none>
I20260812 06:18:27.276916 12864 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:27.276970 12864 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:27.277206 12864 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:27.278774 12864 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/master-0-root/instance:
uuid: "7beab19bcc544108b32b5d47742e8740"
format_stamp: "Formatted at 2026-08-12 06:18:27 on dist-test-slave-k5rr"
I20260812 06:18:27.281996 12864 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:18:27.283854 12889 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:27.284781 12864 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:27.284890 12864 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/master-0-root
uuid: "7beab19bcc544108b32b5d47742e8740"
format_stamp: "Formatted at 2026-08-12 06:18:27 on dist-test-slave-k5rr"
I20260812 06:18:27.284967 12864 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:27.299109 12864 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:27.299633 12864 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:27.299769 12864 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:27.306711 12864 rpc_server.cc:307] RPC server started. Bound to: 127.12.144.62:45109
I20260812 06:18:27.306766 12969 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.144.62:45109 every 8 connection(s)
I20260812 06:18:27.308779 12970 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:27.314072 12970 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740: Bootstrap starting.
I20260812 06:18:27.316321 12970 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:27.317186 12970 log.cc:826] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:27.318704 12970 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740: No bootstrap required, opened a new log
I20260812 06:18:27.321475 12970 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7beab19bcc544108b32b5d47742e8740" member_type: VOTER }
I20260812 06:18:27.321678 12970 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:27.321749 12970 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7beab19bcc544108b32b5d47742e8740, State: Initialized, Role: FOLLOWER
I20260812 06:18:27.322317 12970 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [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: "7beab19bcc544108b32b5d47742e8740" member_type: VOTER }
I20260812 06:18:27.322458 12970 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:27.322502 12970 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:27.322587 12970 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:27.323269 12970 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7beab19bcc544108b32b5d47742e8740" member_type: VOTER }
I20260812 06:18:27.323637 12970 leader_election.cc:304] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [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: 7beab19bcc544108b32b5d47742e8740; no voters: 
I20260812 06:18:27.323886 12970 leader_election.cc:290] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:27.324008 12975 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:27.324213 12975 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [term 1 LEADER]: Becoming Leader. State: Replica: 7beab19bcc544108b32b5d47742e8740, State: Running, Role: LEADER
I20260812 06:18:27.324640 12975 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [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: "7beab19bcc544108b32b5d47742e8740" member_type: VOTER }
I20260812 06:18:27.324815 12970 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:27.326450 12977 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7beab19bcc544108b32b5d47742e8740" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7beab19bcc544108b32b5d47742e8740" member_type: VOTER } }
I20260812 06:18:27.326449 12978 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7beab19bcc544108b32b5d47742e8740. Latest consensus state: current_term: 1 leader_uuid: "7beab19bcc544108b32b5d47742e8740" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7beab19bcc544108b32b5d47742e8740" member_type: VOTER } }
I20260812 06:18:27.326601 12977 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:27.326601 12978 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:27.327015 12864 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:27.327046 12998 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:27.329223 12998 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:27.333729 12998 catalog_manager.cc:1383] Generated new cluster ID: 996bf3f36a694020b099bbd497c82913
I20260812 06:18:27.333788 12998 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:27.344262 12998 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:27.345371 12998 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:27.353893 12998 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740: Generated new TSK 0
I20260812 06:18:27.354579 12998 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:27.359361 12864 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:27.361776 13017 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:27.361816 13020 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:27.361825 13012 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:27.362095 12864 server_base.cc:1061] running on GCE node
I20260812 06:18:27.362267 12864 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:27.362308 12864 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:27.362321 12864 hybrid_clock.cc:648] HybridClock initialized: now 1786515507362321 us; error 0 us; skew 500 ppm
I20260812 06:18:27.363119 12864 webserver.cc:533] Webserver started at http://127.12.144.1:39277/ using document root <none> and password file <none>
I20260812 06:18:27.363282 12864 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:27.363325 12864 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:27.363397 12864 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:27.363734 12864 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/instance:
uuid: "7da078ca6a82448798eba9034b94c569"
format_stamp: "Formatted at 2026-08-12 06:18:27 on dist-test-slave-k5rr"
I20260812 06:18:27.365167 12864 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:27.366109 13031 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:27.366353 12864 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:27.366431 12864 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root
uuid: "7da078ca6a82448798eba9034b94c569"
format_stamp: "Formatted at 2026-08-12 06:18:27 on dist-test-slave-k5rr"
I20260812 06:18:27.366498 12864 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:27.378159 12864 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:27.378798 12864 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:27.379271 12864 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:27.380122 12864 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:27.380175 12864 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:27.380232 12864 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:27.380256 12864 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:27.386258 12864 rpc_server.cc:307] RPC server started. Bound to: 127.12.144.1:41261
I20260812 06:18:27.386296 13145 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.144.1:41261 every 8 connection(s)
I20260812 06:18:27.398314 13147 heartbeater.cc:344] Connected to a master server at 127.12.144.62:45109
I20260812 06:18:27.398545 13147 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:27.398967 13147 heartbeater.cc:507] Master 127.12.144.62:45109 requested a full tablet report, sending...
I20260812 06:18:27.400255 12917 ts_manager.cc:194] Registered new tserver with Master: 7da078ca6a82448798eba9034b94c569 (127.12.144.1:41261)
I20260812 06:18:27.401216 12864 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014373782s
I20260812 06:18:27.402252 12917 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45328
I20260812 06:18:27.409942 12917 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45344:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:27.422425 13084 tablet_service.cc:1511] Processing CreateTablet for tablet f863be875e1949b5bf8fdb117b21b049 (DEFAULT_TABLE table=heavy-update-compaction-test [id=552786a117354634805bc3592461f783]), partition=
I20260812 06:18:27.422874 13084 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f863be875e1949b5bf8fdb117b21b049. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:27.425195 13163 tablet_bootstrap.cc:492] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Bootstrap starting.
I20260812 06:18:27.426069 13163 tablet_bootstrap.cc:654] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:27.427287 13163 tablet_bootstrap.cc:492] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: No bootstrap required, opened a new log
I20260812 06:18:27.427369 13163 ts_tablet_manager.cc:1403] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:27.427760 13163 raft_consensus.cc:359] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7da078ca6a82448798eba9034b94c569" member_type: VOTER last_known_addr { host: "127.12.144.1" port: 41261 } }
I20260812 06:18:27.427851 13163 raft_consensus.cc:385] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:27.427874 13163 raft_consensus.cc:740] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7da078ca6a82448798eba9034b94c569, State: Initialized, Role: FOLLOWER
I20260812 06:18:27.427995 13163 consensus_queue.cc:260] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569 [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: "7da078ca6a82448798eba9034b94c569" member_type: VOTER last_known_addr { host: "127.12.144.1" port: 41261 } }
I20260812 06:18:27.428072 13163 raft_consensus.cc:399] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:27.428108 13163 raft_consensus.cc:493] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:27.428156 13163 raft_consensus.cc:3060] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:27.428830 13163 raft_consensus.cc:515] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7da078ca6a82448798eba9034b94c569" member_type: VOTER last_known_addr { host: "127.12.144.1" port: 41261 } }
I20260812 06:18:27.428959 13163 leader_election.cc:304] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569 [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: 7da078ca6a82448798eba9034b94c569; no voters: 
I20260812 06:18:27.429164 13163 leader_election.cc:290] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:27.429261 13167 raft_consensus.cc:2804] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:27.429425 13167 raft_consensus.cc:697] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569 [term 1 LEADER]: Becoming Leader. State: Replica: 7da078ca6a82448798eba9034b94c569, State: Running, Role: LEADER
I20260812 06:18:27.429495 13163 ts_tablet_manager.cc:1434] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:27.429711 13147 heartbeater.cc:499] Master 127.12.144.62:45109 was elected leader, sending a full tablet report...
I20260812 06:18:27.429629 13167 consensus_queue.cc:237] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569 [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: "7da078ca6a82448798eba9034b94c569" member_type: VOTER last_known_addr { host: "127.12.144.1" port: 41261 } }
I20260812 06:18:27.432328 12917 catalog_manager.cc:5719] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569 reported cstate change: term changed from 0 to 1, leader changed from <none> to 7da078ca6a82448798eba9034b94c569 (127.12.144.1). New cstate: current_term: 1 leader_uuid: "7da078ca6a82448798eba9034b94c569" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7da078ca6a82448798eba9034b94c569" member_type: VOTER last_known_addr { host: "127.12.144.1" port: 41261 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:27.492906 12864 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.020s	sys 0.004s
I20260812 06:18:27.637331 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushMRSOp(f863be875e1949b5bf8fdb117b21b049): perf score=19.054940
I20260812 06:18:27.824659 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushMRSOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.187s	user 0.128s	sys 0.056s Metrics: {"bytes_written":15999661,"cfile_init":1,"compiler_manager_pool.queue_time_us":192,"delete_count":0,"dirs.queue_time_us":97,"dirs.run_cpu_time_us":294,"dirs.run_wall_time_us":1002,"drs_written":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4,"lbm_write_time_us":46590,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"thread_start_us":112,"threads_started":1,"update_count":1950}
I20260812 06:18:27.826088 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling UndoDeltaBlockGCOp(f863be875e1949b5bf8fdb117b21b049): 16821647 bytes on disk
I20260812 06:18:27.826866 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: UndoDeltaBlockGCOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:18:27.827406 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=4.173312
I20260812 06:18:27.846576 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.019s	user 0.009s	sys 0.009s Metrics: {"bytes_written":5702609,"delete_count":0,"lbm_write_time_us":7675,"lbm_writes_lt_1ms":142,"reinsert_count":0,"update_count":695}
I20260812 06:18:27.847069 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling LogGCOp(f863be875e1949b5bf8fdb117b21b049): free 20743880 bytes of WAL
I20260812 06:18:27.847368 13042 log_reader.cc:385] T f863be875e1949b5bf8fdb117b21b049: removed 2 log segments from log reader
I20260812 06:18:27.847465 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000001 (ops 1-6)
I20260812 06:18:27.847543 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000002 (ops 7-11)
I20260812 06:18:27.852336 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: LogGCOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:27.852707 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.196750
I20260812 06:18:27.861616 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":2502679,"delete_count":0,"lbm_write_time_us":3046,"lbm_writes_lt_1ms":64,"reinsert_count":0,"update_count":305}
I20260812 06:18:27.862071 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:28.039314 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.177s	user 0.099s	sys 0.067s Metrics: {"cfile_cache_miss":623,"cfile_cache_miss_bytes":28507938,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":598,"lbm_read_time_us":11649,"lbm_reads_lt_1ms":659,"lbm_write_time_us":31057,"lbm_writes_lt_1ms":633,"peak_mem_usage":74091738,"reinsert_count":0,"spinlock_wait_cycles":2048,"thread_start_us":267,"threads_started":5,"update_count":2950}
I20260812 06:18:28.039805 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=14.095187
I20260812 06:18:28.094177 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.054s	user 0.028s	sys 0.008s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":15977,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.094697 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:28.110633 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5816,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.111088 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:28.281563 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.170s	user 0.106s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":114,"lbm_read_time_us":11658,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26737,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19328,"update_count":2500}
I20260812 06:18:28.282028 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=11.118625
I20260812 06:18:28.317726 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.036s	user 0.020s	sys 0.015s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":12262,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:28.318277 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:28.329885 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.011s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4504,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":450}
I20260812 06:18:28.330302 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:28.489044 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.159s	user 0.102s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713265,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":965,"lbm_read_time_us":9779,"lbm_reads_lt_1ms":468,"lbm_write_time_us":28334,"lbm_writes_lt_1ms":443,"mutex_wait_us":663,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2000}
I20260812 06:18:28.489676 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=10.126437
I20260812 06:18:28.522867 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.033s	user 0.010s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12540,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:28.523484 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:28.548295 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.025s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5251,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.548889 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:28.558641 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3589,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.559031 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:28.698051 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.139s	user 0.126s	sys 0.012s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815803,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":219,"lbm_read_time_us":12022,"lbm_reads_lt_1ms":573,"lbm_write_time_us":25377,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2500}
I20260812 06:18:28.698681 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=11.118625
I20260812 06:18:28.741737 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.043s	user 0.022s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18697,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1550}
I20260812 06:18:28.742271 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:28.768059 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.026s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":5529,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:18:28.768528 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:28.778515 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":3688,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:18:28.778970 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:28.942770 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.164s	user 0.132s	sys 0.025s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":199,"lbm_read_time_us":12798,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31324,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:18:28.943298 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=14.095187
I20260812 06:18:28.998790 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.055s	user 0.027s	sys 0.026s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24349,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.999361 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:29.015519 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.016s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5407,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.016124 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushMRSOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:29.070586 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushMRSOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.054s	user 0.034s	sys 0.001s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":1176,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1536,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":3456}
I20260812 06:18:29.071399 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling LogGCOp(f863be875e1949b5bf8fdb117b21b049): free 120553345 bytes of WAL
I20260812 06:18:29.071651 13042 log_reader.cc:385] T f863be875e1949b5bf8fdb117b21b049: removed 12 log segments from log reader
I20260812 06:18:29.071712 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000003 (ops 12-16)
I20260812 06:18:29.071751 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000004 (ops 17-20)
I20260812 06:18:29.071785 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000005 (ops 21-25)
I20260812 06:18:29.071817 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000006 (ops 26-30)
I20260812 06:18:29.071844 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000007 (ops 31-35)
I20260812 06:18:29.071873 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000008 (ops 36-40)
I20260812 06:18:29.071911 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000009 (ops 41-45)
I20260812 06:18:29.071944 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000010 (ops 46-50)
I20260812 06:18:29.071973 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000011 (ops 51-55)
I20260812 06:18:29.072001 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000012 (ops 56-60)
I20260812 06:18:29.072028 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000013 (ops 61-64)
I20260812 06:18:29.072058 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000014 (ops 65-69)
I20260812 06:18:29.098620 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: LogGCOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:29.098999 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling UndoDeltaBlockGCOp(f863be875e1949b5bf8fdb117b21b049): 472 bytes on disk
I20260812 06:18:29.099419 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: UndoDeltaBlockGCOp(f863be875e1949b5bf8fdb117b21b049) 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:18:29.099882 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=7.149875
I20260812 06:18:29.129756 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.030s	user 0.003s	sys 0.026s Metrics: {"bytes_written":8615322,"delete_count":0,"lbm_write_time_us":8630,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:29.130259 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:29.139312 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.009s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3253,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:29.139715 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:29.393290 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.253s	user 0.160s	sys 0.086s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37123147,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3419,"lbm_read_time_us":16915,"lbm_reads_lt_1ms":874,"lbm_write_time_us":38684,"lbm_writes_lt_1ms":843,"mutex_wait_us":2967,"peak_mem_usage":100395616,"reinsert_count":0,"thread_start_us":97,"threads_started":1,"update_count":4000}
I20260812 06:18:29.393837 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=18.063937
I20260812 06:18:29.442005 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.048s	user 0.037s	sys 0.009s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":20257,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:29.442502 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:29.607532 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.165s	user 0.120s	sys 0.044s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24815566,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":184,"lbm_read_time_us":11360,"lbm_reads_lt_1ms":563,"lbm_write_time_us":27753,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:18:29.608002 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=14.095187
I20260812 06:18:29.665351 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.057s	user 0.030s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20378,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:29.665917 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:29.680723 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5604,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.681243 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:29.856745 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.175s	user 0.101s	sys 0.061s 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":149,"lbm_read_time_us":12534,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26180,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:29.857450 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=14.095187
I20260812 06:18:29.906420 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.049s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19333,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:29.906941 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:29.924804 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.018s	user 0.008s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3701,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.925405 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:30.100910 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.175s	user 0.124s	sys 0.042s 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":353,"dirs.run_cpu_time_us":436,"dirs.run_wall_time_us":4106,"lbm_read_time_us":12072,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28245,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2500}
I20260812 06:18:30.101502 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=14.095187
I20260812 06:18:30.151549 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.050s	user 0.039s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23182,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.152241 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:30.168411 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.016s	user 0.000s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4426,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.169126 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:30.341729 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.172s	user 0.115s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":223,"lbm_read_time_us":12437,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25370,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":68992,"update_count":2500}
I20260812 06:18:30.342231 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=14.095187
I20260812 06:18:30.392779 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.050s	user 0.020s	sys 0.027s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21873,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.393373 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:30.405697 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3731,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.406226 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:30.547338 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.141s	user 0.116s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":560,"lbm_read_time_us":9724,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27281,"lbm_writes_lt_1ms":543,"mutex_wait_us":305,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:18:30.547871 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=10.126437
I20260812 06:18:30.577940 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.030s	user 0.021s	sys 0.007s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":12216,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:30.578465 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:30.589680 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3963,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.590214 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushMRSOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:30.617616 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushMRSOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.027s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1206,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1539,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:30.618364 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling LogGCOp(f863be875e1949b5bf8fdb117b21b049): free 133024437 bytes of WAL
I20260812 06:18:30.618595 13042 log_reader.cc:385] T f863be875e1949b5bf8fdb117b21b049: removed 13 log segments from log reader
I20260812 06:18:30.618643 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000015 (ops 70-74)
I20260812 06:18:30.618673 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000016 (ops 75-79)
I20260812 06:18:30.618705 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000017 (ops 80-84)
I20260812 06:18:30.618737 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000018 (ops 85-89)
I20260812 06:18:30.618768 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000019 (ops 90-94)
I20260812 06:18:30.618799 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000020 (ops 95-99)
I20260812 06:18:30.618830 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000021 (ops 100-104)
I20260812 06:18:30.618862 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000022 (ops 105-108)
I20260812 06:18:30.618893 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000023 (ops 109-113)
I20260812 06:18:30.618922 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000024 (ops 114-118)
I20260812 06:18:30.618953 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000025 (ops 119-123)
I20260812 06:18:30.618983 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000026 (ops 124-128)
I20260812 06:18:30.619014 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000027 (ops 129-133)
I20260812 06:18:30.644217 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: LogGCOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:30.644739 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=3.181125
I20260812 06:18:30.657401 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.012s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4841098,"delete_count":0,"lbm_write_time_us":4713,"lbm_writes_lt_1ms":121,"reinsert_count":0,"update_count":590}
I20260812 06:18:30.657817 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:30.666249 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3364205,"delete_count":0,"lbm_write_time_us":2960,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:18:30.666693 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling UndoDeltaBlockGCOp(f863be875e1949b5bf8fdb117b21b049): 483 bytes on disk
I20260812 06:18:30.667455 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: UndoDeltaBlockGCOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:18:30.668121 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:30.847002 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.179s	user 0.151s	sys 0.024s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918321,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":922,"lbm_read_time_us":10493,"lbm_reads_lt_1ms":674,"lbm_write_time_us":29191,"lbm_writes_lt_1ms":643,"mutex_wait_us":340,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":68,"threads_started":1,"update_count":3000}
I20260812 06:18:30.847744 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=14.095187
I20260812 06:18:30.902309 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.054s	user 0.028s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21008,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.902822 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:30.913966 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4133,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.914454 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:31.085744 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.171s	user 0.111s	sys 0.051s 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":300,"lbm_read_time_us":11514,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24656,"lbm_writes_lt_1ms":543,"mutex_wait_us":80,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:18:31.086315 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=14.095187
I20260812 06:18:31.137802 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.051s	user 0.027s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21150,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.138298 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:31.150715 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4552,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.151327 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:31.291075 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.140s	user 0.092s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":198,"lbm_read_time_us":9985,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27396,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16128,"update_count":2500}
I20260812 06:18:31.291755 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=11.118625
I20260812 06:18:31.320580 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.029s	user 0.008s	sys 0.017s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":12025,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:31.321301 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:31.346844 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.025s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6006,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":450}
I20260812 06:18:31.347410 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:31.357424 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3732,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.357990 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:31.505445 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.147s	user 0.106s	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":496,"lbm_read_time_us":11192,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29724,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2500}
I20260812 06:18:31.506039 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=10.126437
I20260812 06:18:31.535709 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.029s	user 0.013s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12732,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:31.536161 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:31.551011 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.015s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5036,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.551530 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:31.671743 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.120s	user 0.094s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":569,"lbm_read_time_us":9532,"lbm_reads_lt_1ms":468,"lbm_write_time_us":22101,"lbm_writes_lt_1ms":443,"mutex_wait_us":303,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":27776,"update_count":2000}
I20260812 06:18:31.672271 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=10.126437
I20260812 06:18:31.716270 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.044s	user 0.034s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17369,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:31.716794 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:31.728174 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3947,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.728626 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:31.850628 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.122s	user 0.102s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1369,"lbm_read_time_us":9924,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22278,"lbm_writes_lt_1ms":443,"mutex_wait_us":841,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:18:31.851083 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=10.126437
I20260812 06:18:31.890064 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.039s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13096,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:31.890674 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:31.905334 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5616,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.905779 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushMRSOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:31.932690 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushMRSOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1193,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1272,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:31.933419 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:32.062254 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.129s	user 0.100s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":124,"lbm_read_time_us":8257,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21587,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:18:32.062883 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling LogGCOp(f863be875e1949b5bf8fdb117b21b049): free 124710518 bytes of WAL
I20260812 06:18:32.063125 13042 log_reader.cc:385] T f863be875e1949b5bf8fdb117b21b049: removed 12 log segments from log reader
I20260812 06:18:32.063215 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000028 (ops 134-138)
I20260812 06:18:32.063308 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000029 (ops 139-143)
I20260812 06:18:32.063383 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000030 (ops 144-148)
I20260812 06:18:32.063450 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000031 (ops 149-153)
I20260812 06:18:32.063514 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000032 (ops 154-158)
I20260812 06:18:32.063557 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000033 (ops 159-163)
I20260812 06:18:32.063583 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000034 (ops 164-168)
I20260812 06:18:32.063634 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000035 (ops 169-173)
I20260812 06:18:32.063674 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000036 (ops 174-178)
I20260812 06:18:32.063700 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000037 (ops 179-183)
I20260812 06:18:32.063723 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000038 (ops 184-188)
I20260812 06:18:32.063746 13042 log.cc:1079] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/f863be875e1949b5bf8fdb117b21b049/wal-000000039 (ops 189-193)
I20260812 06:18:32.088542 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: LogGCOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.025s	user 0.003s	sys 0.019s Metrics: {}
I20260812 06:18:32.088963 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling UndoDeltaBlockGCOp(f863be875e1949b5bf8fdb117b21b049): 462 bytes on disk
I20260812 06:18:32.089432 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: UndoDeltaBlockGCOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:18:32.090023 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=14.095187
I20260812 06:18:32.128151 12864 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.635s	user 1.694s	sys 0.126s
I20260812 06:18:32.131893 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.042s	user 0.029s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19169,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:32.132400 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049): perf score=2.188937
I20260812 06:18:32.141175 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: FlushDeltaMemStoresOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.009s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3465,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.141620 13149 maintenance_manager.cc:419] P 7da078ca6a82448798eba9034b94c569: Scheduling MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049): perf score=1.000000
I20260812 06:18:32.159490 12864 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.031s	user 0.003s	sys 0.000s
I20260812 06:18:32.160181 12864 tablet_server.cc:179] TabletServer@127.12.144.1:0 shutting down...
I20260812 06:18:32.259982 13042 maintenance_manager.cc:643] P 7da078ca6a82448798eba9034b94c569: MajorDeltaCompactionOp(f863be875e1949b5bf8fdb117b21b049) complete. Timing: real 0.118s	user 0.099s	sys 0.018s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4303385,"cfile_cache_miss":502,"cfile_cache_miss_bytes":20512298,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":237,"lbm_read_time_us":8401,"lbm_reads_lt_1ms":518,"lbm_write_time_us":22073,"lbm_writes_lt_1ms":543,"mutex_wait_us":90,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:32.260736 12864 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:32.261195 12864 tablet_replica.cc:333] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569: stopping tablet replica
I20260812 06:18:32.261423 12864 raft_consensus.cc:2243] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:32.261654 12864 raft_consensus.cc:2272] T f863be875e1949b5bf8fdb117b21b049 P 7da078ca6a82448798eba9034b94c569 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:32.266240 12864 tablet_server.cc:196] TabletServer@127.12.144.1:0 shutdown complete.
I20260812 06:18:32.305841 12864 master.cc:562] Master@127.12.144.62:45109 shutting down...
I20260812 06:18:32.309355 12864 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:32.309556 12864 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:32.309631 12864 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7beab19bcc544108b32b5d47742e8740: stopping tablet replica
I20260812 06:18:32.321650 12864 master.cc:584] Master@127.12.144.62:45109 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5130 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:32.395620 12864 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.144.62:33087
I20260812 06:18:32.396001 12864 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:32.397945 13195 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:32.398033 12864 server_base.cc:1061] running on GCE node
W20260812 06:18:32.398185 13196 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:32.398219 13199 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:32.398455 12864 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:32.398502 12864 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:32.398521 12864 hybrid_clock.cc:648] HybridClock initialized: now 1786515512398521 us; error 0 us; skew 500 ppm
I20260812 06:18:32.399309 12864 webserver.cc:533] Webserver started at http://127.12.144.62:36617/ using document root <none> and password file <none>
I20260812 06:18:32.399463 12864 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:32.399511 12864 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:32.399585 12864 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:32.399955 12864 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/master-0-root/instance:
uuid: "51a33b31f95243b7a24478a6bf78ceb5"
format_stamp: "Formatted at 2026-08-12 06:18:32 on dist-test-slave-k5rr"
I20260812 06:18:32.401387 12864 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:32.402297 13205 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:32.402513 12864 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:32.402580 12864 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/master-0-root
uuid: "51a33b31f95243b7a24478a6bf78ceb5"
format_stamp: "Formatted at 2026-08-12 06:18:32 on dist-test-slave-k5rr"
I20260812 06:18:32.402647 12864 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:32.426787 12864 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:32.427182 12864 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:32.431162 12864 rpc_server.cc:307] RPC server started. Bound to: 127.12.144.62:33087
I20260812 06:18:32.441682 13295 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.144.62:33087 every 8 connection(s)
I20260812 06:18:32.448884 13296 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:32.451330 13296 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5: Bootstrap starting.
I20260812 06:18:32.452301 13296 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:32.453465 13296 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5: No bootstrap required, opened a new log
I20260812 06:18:32.453917 13296 raft_consensus.cc:359] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "51a33b31f95243b7a24478a6bf78ceb5" member_type: VOTER }
I20260812 06:18:32.454023 13296 raft_consensus.cc:385] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:32.454061 13296 raft_consensus.cc:740] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 51a33b31f95243b7a24478a6bf78ceb5, State: Initialized, Role: FOLLOWER
I20260812 06:18:32.454236 13296 consensus_queue.cc:260] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [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: "51a33b31f95243b7a24478a6bf78ceb5" member_type: VOTER }
I20260812 06:18:32.454330 13296 raft_consensus.cc:399] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:32.454378 13296 raft_consensus.cc:493] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:32.454427 13296 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:32.455243 13296 raft_consensus.cc:515] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "51a33b31f95243b7a24478a6bf78ceb5" member_type: VOTER }
I20260812 06:18:32.455397 13296 leader_election.cc:304] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [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: 51a33b31f95243b7a24478a6bf78ceb5; no voters: 
I20260812 06:18:32.455577 13296 leader_election.cc:290] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:32.455689 13299 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:32.455928 13299 raft_consensus.cc:697] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [term 1 LEADER]: Becoming Leader. State: Replica: 51a33b31f95243b7a24478a6bf78ceb5, State: Running, Role: LEADER
I20260812 06:18:32.456001 13296 sys_catalog.cc:565] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:32.456118 13299 consensus_queue.cc:237] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [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: "51a33b31f95243b7a24478a6bf78ceb5" member_type: VOTER }
I20260812 06:18:32.456529 13300 sys_catalog.cc:455] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "51a33b31f95243b7a24478a6bf78ceb5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "51a33b31f95243b7a24478a6bf78ceb5" member_type: VOTER } }
I20260812 06:18:32.456554 13302 sys_catalog.cc:455] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 51a33b31f95243b7a24478a6bf78ceb5. Latest consensus state: current_term: 1 leader_uuid: "51a33b31f95243b7a24478a6bf78ceb5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "51a33b31f95243b7a24478a6bf78ceb5" member_type: VOTER } }
I20260812 06:18:32.456660 13300 sys_catalog.cc:458] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:32.456678 13302 sys_catalog.cc:458] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:32.457247 13307 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:32.457955 13307 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:32.458153 12864 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:32.459919 13307 catalog_manager.cc:1383] Generated new cluster ID: 30002e8d63794d1d8bb57990060ae23b
I20260812 06:18:32.459980 13307 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:32.475045 13307 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:32.475579 13307 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:32.485733 13307 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5: Generated new TSK 0
I20260812 06:18:32.485913 13307 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:32.490480 12864 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:32.492385 13327 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:32.492388 13328 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:32.492609 13335 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:32.492637 12864 server_base.cc:1061] running on GCE node
I20260812 06:18:32.492954 12864 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:32.493028 12864 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:32.493057 12864 hybrid_clock.cc:648] HybridClock initialized: now 1786515512493056 us; error 0 us; skew 500 ppm
I20260812 06:18:32.493901 12864 webserver.cc:533] Webserver started at http://127.12.144.1:44033/ using document root <none> and password file <none>
I20260812 06:18:32.494045 12864 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:32.494091 12864 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:32.494164 12864 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:32.494539 12864 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/instance:
uuid: "3e87f3b97029446b9594f8daae27fa6c"
format_stamp: "Formatted at 2026-08-12 06:18:32 on dist-test-slave-k5rr"
I20260812 06:18:32.495952 12864 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:32.496840 13341 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:32.497084 12864 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:32.497155 12864 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root
uuid: "3e87f3b97029446b9594f8daae27fa6c"
format_stamp: "Formatted at 2026-08-12 06:18:32 on dist-test-slave-k5rr"
I20260812 06:18:32.497221 12864 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:32.509651 12864 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:32.510051 12864 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:32.510358 12864 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:32.510862 12864 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:32.510926 12864 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:32.510975 12864 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:32.511008 12864 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:32.516206 12864 rpc_server.cc:307] RPC server started. Bound to: 127.12.144.1:35627
I20260812 06:18:32.516242 13451 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.144.1:35627 every 8 connection(s)
I20260812 06:18:32.524585 13452 heartbeater.cc:344] Connected to a master server at 127.12.144.62:33087
I20260812 06:18:32.524688 13452 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:32.524902 13452 heartbeater.cc:507] Master 127.12.144.62:33087 requested a full tablet report, sending...
I20260812 06:18:32.525578 13239 ts_manager.cc:194] Registered new tserver with Master: 3e87f3b97029446b9594f8daae27fa6c (127.12.144.1:35627)
I20260812 06:18:32.525779 12864 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009061598s
I20260812 06:18:32.526341 13239 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51978
I20260812 06:18:32.532932 13239 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51980:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:32.542517 13394 tablet_service.cc:1511] Processing CreateTablet for tablet 3eec2975db1d4da1a6045d247e2cc91e (DEFAULT_TABLE table=heavy-update-compaction-test [id=56b69aacb0ef4fe39947f983665c2a60]), partition=
I20260812 06:18:32.542768 13394 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3eec2975db1d4da1a6045d247e2cc91e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:32.544854 13478 tablet_bootstrap.cc:492] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Bootstrap starting.
I20260812 06:18:32.546018 13478 tablet_bootstrap.cc:654] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:32.547310 13478 tablet_bootstrap.cc:492] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: No bootstrap required, opened a new log
I20260812 06:18:32.547406 13478 ts_tablet_manager.cc:1403] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:32.547849 13478 raft_consensus.cc:359] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3e87f3b97029446b9594f8daae27fa6c" member_type: VOTER last_known_addr { host: "127.12.144.1" port: 35627 } }
I20260812 06:18:32.547938 13478 raft_consensus.cc:385] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:32.547963 13478 raft_consensus.cc:740] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3e87f3b97029446b9594f8daae27fa6c, State: Initialized, Role: FOLLOWER
I20260812 06:18:32.548079 13478 consensus_queue.cc:260] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c [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: "3e87f3b97029446b9594f8daae27fa6c" member_type: VOTER last_known_addr { host: "127.12.144.1" port: 35627 } }
I20260812 06:18:32.548149 13478 raft_consensus.cc:399] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:32.548173 13478 raft_consensus.cc:493] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:32.548240 13478 raft_consensus.cc:3060] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:32.548915 13478 raft_consensus.cc:515] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3e87f3b97029446b9594f8daae27fa6c" member_type: VOTER last_known_addr { host: "127.12.144.1" port: 35627 } }
I20260812 06:18:32.549062 13478 leader_election.cc:304] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c [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: 3e87f3b97029446b9594f8daae27fa6c; no voters: 
I20260812 06:18:32.549263 13478 leader_election.cc:290] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:32.549415 13481 raft_consensus.cc:2804] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:32.549672 13452 heartbeater.cc:499] Master 127.12.144.62:33087 was elected leader, sending a full tablet report...
I20260812 06:18:32.549702 13481 raft_consensus.cc:697] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c [term 1 LEADER]: Becoming Leader. State: Replica: 3e87f3b97029446b9594f8daae27fa6c, State: Running, Role: LEADER
I20260812 06:18:32.549896 13478 ts_tablet_manager.cc:1434] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:32.549856 13481 consensus_queue.cc:237] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c [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: "3e87f3b97029446b9594f8daae27fa6c" member_type: VOTER last_known_addr { host: "127.12.144.1" port: 35627 } }
I20260812 06:18:32.551277 13239 catalog_manager.cc:5719] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c reported cstate change: term changed from 0 to 1, leader changed from <none> to 3e87f3b97029446b9594f8daae27fa6c (127.12.144.1). New cstate: current_term: 1 leader_uuid: "3e87f3b97029446b9594f8daae27fa6c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3e87f3b97029446b9594f8daae27fa6c" member_type: VOTER last_known_addr { host: "127.12.144.1" port: 35627 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:32.608505 12864 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.014s	sys 0.008s
I20260812 06:18:32.767168 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushMRSOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=23.023690
I20260812 06:18:32.915812 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushMRSOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.148s	user 0.113s	sys 0.032s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":173,"dirs.run_wall_time_us":740,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38058,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:18:32.916432 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling LogGCOp(3eec2975db1d4da1a6045d247e2cc91e): free 20743880 bytes of WAL
I20260812 06:18:32.916653 13354 log_reader.cc:385] T 3eec2975db1d4da1a6045d247e2cc91e: removed 2 log segments from log reader
I20260812 06:18:32.916700 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000001 (ops 1-6)
I20260812 06:18:32.916736 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000002 (ops 7-11)
I20260812 06:18:32.920151 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: LogGCOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:32.920451 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:32.933331 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4421,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.933872 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling UndoDeltaBlockGCOp(3eec2975db1d4da1a6045d247e2cc91e): 20513815 bytes on disk
I20260812 06:18:32.934249 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: UndoDeltaBlockGCOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4}
I20260812 06:18:32.934626 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:33.072594 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.138s	user 0.085s	sys 0.052s 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":537,"lbm_read_time_us":10724,"lbm_reads_lt_1ms":460,"lbm_write_time_us":23397,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":284,"threads_started":5,"update_count":2000}
I20260812 06:18:33.073350 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=10.126437
I20260812 06:18:33.109270 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.036s	user 0.025s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15009,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.109807 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:33.120110 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3805,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.120529 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:33.271560 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.151s	user 0.112s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":613,"lbm_read_time_us":12127,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24436,"lbm_writes_lt_1ms":443,"mutex_wait_us":5,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2000}
I20260812 06:18:33.272190 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=10.126437
I20260812 06:18:33.302657 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.030s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13094,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.303282 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:33.315404 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4427,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.315891 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:33.449365 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.133s	user 0.109s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":177,"lbm_read_time_us":9908,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22072,"lbm_writes_lt_1ms":443,"mutex_wait_us":76,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:18:33.449857 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=10.126437
I20260812 06:18:33.491426 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.041s	user 0.024s	sys 0.004s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":12939,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.491992 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:33.504169 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4721,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.504588 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:33.626518 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.122s	user 0.098s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713274,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":192,"lbm_read_time_us":10096,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21413,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2000}
I20260812 06:18:33.627094 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=10.126437
I20260812 06:18:33.666203 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.039s	user 0.012s	sys 0.024s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17173,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.666733 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:33.682040 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5517,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.682539 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:33.801478 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.119s	user 0.095s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":227,"lbm_read_time_us":8340,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23881,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:18:33.802011 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=10.126437
I20260812 06:18:33.847817 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.046s	user 0.023s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16796,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.848436 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:33.860361 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4616,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.860909 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:34.011826 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.151s	user 0.087s	sys 0.063s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":699,"lbm_read_time_us":10965,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24261,"lbm_writes_lt_1ms":443,"mutex_wait_us":302,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":30080,"update_count":2000}
I20260812 06:18:34.012444 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=10.126437
I20260812 06:18:34.058990 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.046s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15623,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:34.059473 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:34.074425 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5477,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.075102 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushMRSOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:34.101208 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushMRSOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.026s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1225,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1623,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:34.101864 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling LogGCOp(3eec2975db1d4da1a6045d247e2cc91e): free 112692363 bytes of WAL
I20260812 06:18:34.102100 13354 log_reader.cc:385] T 3eec2975db1d4da1a6045d247e2cc91e: removed 11 log segments from log reader
I20260812 06:18:34.102149 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000003 (ops 12-16)
I20260812 06:18:34.102186 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000004 (ops 17-21)
I20260812 06:18:34.102221 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000005 (ops 22-26)
I20260812 06:18:34.102272 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000006 (ops 27-31)
I20260812 06:18:34.102304 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000007 (ops 32-36)
I20260812 06:18:34.102337 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000008 (ops 37-41)
I20260812 06:18:34.102367 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000009 (ops 42-46)
I20260812 06:18:34.102398 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000010 (ops 47-51)
I20260812 06:18:34.102428 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000011 (ops 52-56)
I20260812 06:18:34.102458 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000012 (ops 57-61)
I20260812 06:18:34.102488 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000013 (ops 62-66)
I20260812 06:18:34.123180 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: LogGCOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.021s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:18:34.123591 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=3.181125
I20260812 06:18:34.144791 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.021s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":3998,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:34.145361 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:34.154381 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.009s	user 0.006s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3287,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:34.154901 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:34.348697 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.194s	user 0.155s	sys 0.038s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918324,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":182,"lbm_read_time_us":13414,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31887,"lbm_writes_lt_1ms":643,"mutex_wait_us":48,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3968,"thread_start_us":72,"threads_started":1,"update_count":3000}
I20260812 06:18:34.349447 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling UndoDeltaBlockGCOp(3eec2975db1d4da1a6045d247e2cc91e): 447 bytes on disk
I20260812 06:18:34.349942 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: UndoDeltaBlockGCOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4}
I20260812 06:18:34.350611 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=14.095187
I20260812 06:18:34.402679 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.052s	user 0.024s	sys 0.026s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18416,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.403272 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:34.418699 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5882,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.419217 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:34.600818 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.181s	user 0.118s	sys 0.056s 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":225,"lbm_read_time_us":13179,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27858,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:34.601378 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=14.095187
I20260812 06:18:34.645206 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.044s	user 0.040s	sys 0.000s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17687,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.645723 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:34.668813 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.023s	user 0.007s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5913,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.669407 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:34.846154 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.177s	user 0.110s	sys 0.057s 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":676,"lbm_read_time_us":12873,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26781,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:18:34.846724 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=14.095187
I20260812 06:18:34.897095 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.050s	user 0.037s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20145,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.897572 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:34.908033 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3770,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.908588 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:35.082098 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.173s	user 0.103s	sys 0.059s 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":131,"lbm_read_time_us":11161,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28421,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:18:35.082734 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=14.095187
I20260812 06:18:35.134114 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.051s	user 0.027s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21742,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:35.134678 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:35.146581 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4120,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.147089 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:35.295286 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.148s	user 0.118s	sys 0.019s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":915,"lbm_read_time_us":10140,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28080,"lbm_writes_lt_1ms":543,"mutex_wait_us":280,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:18:35.296010 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=14.095187
I20260812 06:18:35.340780 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.045s	user 0.024s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19460,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:35.341342 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:35.352299 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3854,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.352806 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:35.493067 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.140s	user 0.108s	sys 0.031s 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":885,"lbm_read_time_us":9877,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26576,"lbm_writes_lt_1ms":543,"mutex_wait_us":541,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2500}
I20260812 06:18:35.495963 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=11.118625
I20260812 06:18:35.523382 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.027s	user 0.009s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":11795,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:35.524024 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:35.533380 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3331,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:35.533934 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushMRSOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:35.568040 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushMRSOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.034s	user 0.029s	sys 0.003s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":257,"dirs.run_wall_time_us":1257,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2762,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":38,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:35.568743 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling LogGCOp(3eec2975db1d4da1a6045d247e2cc91e): free 136728237 bytes of WAL
I20260812 06:18:35.568989 13354 log_reader.cc:385] T 3eec2975db1d4da1a6045d247e2cc91e: removed 13 log segments from log reader
I20260812 06:18:35.569056 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000014 (ops 67-71)
I20260812 06:18:35.569088 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000015 (ops 72-76)
I20260812 06:18:35.569123 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000016 (ops 77-81)
I20260812 06:18:35.569146 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000017 (ops 82-86)
I20260812 06:18:35.569178 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000018 (ops 87-91)
I20260812 06:18:35.569209 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000019 (ops 92-96)
I20260812 06:18:35.569242 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000020 (ops 97-101)
I20260812 06:18:35.569273 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000021 (ops 102-106)
I20260812 06:18:35.569304 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000022 (ops 107-111)
I20260812 06:18:35.569336 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000023 (ops 112-116)
I20260812 06:18:35.569368 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000024 (ops 117-121)
I20260812 06:18:35.569401 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000025 (ops 122-126)
I20260812 06:18:35.569432 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000026 (ops 127-131)
I20260812 06:18:35.594228 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: LogGCOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:18:35.594590 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=3.181125
I20260812 06:18:35.607010 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.012s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4605,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:35.607486 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:35.621995 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.014s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4911,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:35.622573 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:35.796561 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.174s	user 0.122s	sys 0.049s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918316,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":670,"lbm_read_time_us":13034,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36106,"lbm_writes_lt_1ms":643,"mutex_wait_us":56,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18304,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:18:35.797189 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=14.095187
I20260812 06:18:35.855633 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.058s	user 0.026s	sys 0.030s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25471,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:35.856369 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling UndoDeltaBlockGCOp(3eec2975db1d4da1a6045d247e2cc91e): 482 bytes on disk
I20260812 06:18:35.857101 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: UndoDeltaBlockGCOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4}
I20260812 06:18:35.857820 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:35.884116 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.026s	user 0.002s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5870,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.884619 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:35.898989 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5300,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.899516 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:36.058197 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.158s	user 0.130s	sys 0.027s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918214,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":651,"lbm_read_time_us":13420,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30243,"lbm_writes_lt_1ms":643,"mutex_wait_us":283,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":3000}
I20260812 06:18:36.058739 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=14.095187
I20260812 06:18:36.114288 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.055s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23518,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:36.114866 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:36.126535 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4098,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.127099 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:36.288861 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.162s	user 0.118s	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":271,"lbm_read_time_us":13063,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27901,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2500}
I20260812 06:18:36.289495 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=14.095187
I20260812 06:18:36.340723 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.051s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19819,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:36.341391 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:36.488744 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.147s	user 0.084s	sys 0.053s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":711,"lbm_read_time_us":9750,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22693,"lbm_writes_lt_1ms":443,"mutex_wait_us":305,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:36.489262 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=14.095187
I20260812 06:18:36.532999 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.044s	user 0.022s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18239,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:36.533530 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:36.543958 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3689,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.544639 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:36.714200 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.169s	user 0.126s	sys 0.040s 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":606,"lbm_read_time_us":11008,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28832,"lbm_writes_lt_1ms":543,"mutex_wait_us":303,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":37888,"update_count":2500}
I20260812 06:18:36.714663 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=14.095187
I20260812 06:18:36.763918 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.049s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19621,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:36.764499 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:36.775384 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3758,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.775892 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:36.939428 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.163s	user 0.130s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":907,"lbm_read_time_us":8973,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32249,"lbm_writes_lt_1ms":543,"mutex_wait_us":277,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:18:36.939975 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=14.095187
I20260812 06:18:36.989199 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.049s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20666,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:36.989832 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=2.188937
I20260812 06:18:37.001173 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3938,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.001670 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushMRSOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:37.031772 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushMRSOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":1390,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1596,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:37.032570 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling LogGCOp(3eec2975db1d4da1a6045d247e2cc91e): free 133024646 bytes of WAL
I20260812 06:18:37.032829 13354 log_reader.cc:385] T 3eec2975db1d4da1a6045d247e2cc91e: removed 13 log segments from log reader
I20260812 06:18:37.032878 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000027 (ops 132-136)
I20260812 06:18:37.032918 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000028 (ops 137-140)
I20260812 06:18:37.032951 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000029 (ops 141-145)
I20260812 06:18:37.032976 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000030 (ops 146-150)
I20260812 06:18:37.033028 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000031 (ops 151-155)
I20260812 06:18:37.033066 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000032 (ops 156-160)
I20260812 06:18:37.033092 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000033 (ops 161-165)
I20260812 06:18:37.033114 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000034 (ops 166-170)
I20260812 06:18:37.033146 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000035 (ops 171-175)
I20260812 06:18:37.033174 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000036 (ops 176-180)
I20260812 06:18:37.033206 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000037 (ops 181-185)
I20260812 06:18:37.033237 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000038 (ops 186-190)
I20260812 06:18:37.033269 13354 log.cc:1079] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: Deleting log segment in path: /tmp/dist-test-taskBwKKsc/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515507255679-12864-0/minicluster-data/ts-0-root/wals/3eec2975db1d4da1a6045d247e2cc91e/wal-000000039 (ops 191-195)
I20260812 06:18:37.061822 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: LogGCOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.029s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:18:37.062379 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling UndoDeltaBlockGCOp(3eec2975db1d4da1a6045d247e2cc91e): 492 bytes on disk
I20260812 06:18:37.063063 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: UndoDeltaBlockGCOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:18:37.063684 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=4.173312
I20260812 06:18:37.090553 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.027s	user 0.007s	sys 0.018s Metrics: {"bytes_written":5989776,"delete_count":0,"lbm_write_time_us":6994,"lbm_writes_lt_1ms":149,"reinsert_count":0,"update_count":730}
I20260812 06:18:37.091014 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.196750
I20260812 06:18:37.101094 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: FlushDeltaMemStoresOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":2215504,"delete_count":0,"lbm_write_time_us":3228,"lbm_writes_lt_1ms":57,"reinsert_count":0,"update_count":270}
I20260812 06:18:37.101630 13453 maintenance_manager.cc:419] P 3e87f3b97029446b9594f8daae27fa6c: Scheduling MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e): perf score=1.000000
I20260812 06:18:37.203862 12864 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.595s	user 1.645s	sys 0.169s
I20260812 06:18:37.308616 12864 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.104s	user 0.001s	sys 0.000s
I20260812 06:18:37.309182 12864 tablet_server.cc:179] TabletServer@127.12.144.1:0 shutting down...
I20260812 06:18:37.317260 13354 maintenance_manager.cc:643] P 3e87f3b97029446b9594f8daae27fa6c: MajorDeltaCompactionOp(3eec2975db1d4da1a6045d247e2cc91e) complete. Timing: real 0.215s	user 0.135s	sys 0.075s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020702,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":4132,"lbm_read_time_us":16774,"lbm_reads_lt_1ms":770,"lbm_write_time_us":33812,"lbm_writes_lt_1ms":743,"mutex_wait_us":3563,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":16768,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:18:37.318070 12864 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:37.318357 12864 tablet_replica.cc:333] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c: stopping tablet replica
I20260812 06:18:37.318527 12864 raft_consensus.cc:2243] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:37.318699 12864 raft_consensus.cc:2272] T 3eec2975db1d4da1a6045d247e2cc91e P 3e87f3b97029446b9594f8daae27fa6c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:37.323171 12864 tablet_server.cc:196] TabletServer@127.12.144.1:0 shutdown complete.
I20260812 06:18:37.370348 12864 master.cc:562] Master@127.12.144.62:33087 shutting down...
I20260812 06:18:37.373508 12864 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:37.373689 12864 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:37.373764 12864 tablet_replica.cc:333] T 00000000000000000000000000000000 P 51a33b31f95243b7a24478a6bf78ceb5: stopping tablet replica
I20260812 06:18:37.385967 12864 master.cc:584] Master@127.12.144.62:33087 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5062 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10193 ms total)

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