[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:51.986891 14892 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.14.139.62:35357
I20260812 06:19:51.989814 14892 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:51.990561 14892 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:52.004472 14898 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:52.004657 14892 server_base.cc:1061] running on GCE node
W20260812 06:19:52.004477 14900 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:52.005273 14897 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:52.006349 14892 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:52.006613 14892 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:52.006949 14892 hybrid_clock.cc:648] HybridClock initialized: now 1786515592006874 us; error 0 us; skew 500 ppm
I20260812 06:19:52.011171 14892 webserver.cc:533] Webserver started at http://127.14.139.62:34345/ using document root <none> and password file <none>
I20260812 06:19:52.012838 14892 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:52.013049 14892 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:52.014508 14892 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:52.018896 14892 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/master-0-root/instance:
uuid: "28055ce5f30f4fef8f2a5cea47d70647"
format_stamp: "Formatted at 2026-08-12 06:19:52 on dist-test-slave-8n49"
I20260812 06:19:52.029510 14892 fs_manager.cc:696] Time spent creating directory manager: real 0.009s	user 0.002s	sys 0.005s
I20260812 06:19:52.036770 14905 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:52.039955 14892 fs_manager.cc:730] Time spent opening block manager: real 0.007s	user 0.003s	sys 0.000s
I20260812 06:19:52.040725 14892 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/master-0-root
uuid: "28055ce5f30f4fef8f2a5cea47d70647"
format_stamp: "Formatted at 2026-08-12 06:19:52 on dist-test-slave-8n49"
I20260812 06:19:52.041128 14892 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:52.070631 14892 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:52.072151 14892 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:52.072365 14892 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:52.084803 14892 rpc_server.cc:307] RPC server started. Bound to: 127.14.139.62:35357
I20260812 06:19:52.085041 14963 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.139.62:35357 every 8 connection(s)
I20260812 06:19:52.088850 14964 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:52.099030 14964 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647: Bootstrap starting.
I20260812 06:19:52.105813 14964 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:52.107879 14964 log.cc:826] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:52.111572 14964 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647: No bootstrap required, opened a new log
I20260812 06:19:52.115495 14964 raft_consensus.cc:359] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28055ce5f30f4fef8f2a5cea47d70647" member_type: VOTER }
I20260812 06:19:52.115677 14964 raft_consensus.cc:385] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:52.115754 14964 raft_consensus.cc:740] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 28055ce5f30f4fef8f2a5cea47d70647, State: Initialized, Role: FOLLOWER
I20260812 06:19:52.117362 14964 consensus_queue.cc:260] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [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: "28055ce5f30f4fef8f2a5cea47d70647" member_type: VOTER }
I20260812 06:19:52.117635 14964 raft_consensus.cc:399] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:52.117727 14964 raft_consensus.cc:493] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:52.118115 14964 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:52.120471 14964 raft_consensus.cc:515] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28055ce5f30f4fef8f2a5cea47d70647" member_type: VOTER }
I20260812 06:19:52.121973 14964 leader_election.cc:304] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [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: 28055ce5f30f4fef8f2a5cea47d70647; no voters: 
I20260812 06:19:52.123282 14964 leader_election.cc:290] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:52.123719 14968 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:52.124538 14968 raft_consensus.cc:697] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [term 1 LEADER]: Becoming Leader. State: Replica: 28055ce5f30f4fef8f2a5cea47d70647, State: Running, Role: LEADER
I20260812 06:19:52.125206 14968 consensus_queue.cc:237] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [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: "28055ce5f30f4fef8f2a5cea47d70647" member_type: VOTER }
I20260812 06:19:52.125471 14964 sys_catalog.cc:565] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:52.129958 14971 sys_catalog.cc:455] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 28055ce5f30f4fef8f2a5cea47d70647. Latest consensus state: current_term: 1 leader_uuid: "28055ce5f30f4fef8f2a5cea47d70647" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28055ce5f30f4fef8f2a5cea47d70647" member_type: VOTER } }
I20260812 06:19:52.130066 14969 sys_catalog.cc:455] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "28055ce5f30f4fef8f2a5cea47d70647" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28055ce5f30f4fef8f2a5cea47d70647" member_type: VOTER } }
I20260812 06:19:52.130919 14971 sys_catalog.cc:458] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:52.130945 14969 sys_catalog.cc:458] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:52.132474 14984 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:52.132644 14892 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:52.138898 14984 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:52.157568 14984 catalog_manager.cc:1383] Generated new cluster ID: f269105c23ef455993896609abfa02e8
I20260812 06:19:52.158609 14984 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:52.196635 14984 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:52.198493 14984 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:52.233438 14984 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647: Generated new TSK 0
I20260812 06:19:52.235212 14984 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:52.262953 14892 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:52.266139 14993 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:52.266374 14996 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:52.266469 14892 server_base.cc:1061] running on GCE node
W20260812 06:19:52.266603 14994 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:52.266899 14892 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:52.266980 14892 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:52.267006 14892 hybrid_clock.cc:648] HybridClock initialized: now 1786515592267006 us; error 0 us; skew 500 ppm
I20260812 06:19:52.269657 14892 webserver.cc:533] Webserver started at http://127.14.139.1:45447/ using document root <none> and password file <none>
I20260812 06:19:52.270153 14892 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:52.270401 14892 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:52.270514 14892 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:52.271672 14892 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/instance:
uuid: "6d645f7352044b45b631a3eff1fe676b"
format_stamp: "Formatted at 2026-08-12 06:19:52 on dist-test-slave-8n49"
I20260812 06:19:52.275380 14892 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.004s
I20260812 06:19:52.277177 15002 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:52.277963 14892 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:52.278080 14892 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root
uuid: "6d645f7352044b45b631a3eff1fe676b"
format_stamp: "Formatted at 2026-08-12 06:19:52 on dist-test-slave-8n49"
I20260812 06:19:52.278360 14892 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:52.315548 14892 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:52.316082 14892 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:52.317283 14892 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:52.318821 14892 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:52.318884 14892 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:52.318996 14892 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:52.319044 14892 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:52.336025 14892 rpc_server.cc:307] RPC server started. Bound to: 127.14.139.1:40129
I20260812 06:19:52.336056 15080 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.139.1:40129 every 8 connection(s)
I20260812 06:19:52.360764 15081 heartbeater.cc:344] Connected to a master server at 127.14.139.62:35357
I20260812 06:19:52.361055 15081 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:52.361560 15081 heartbeater.cc:507] Master 127.14.139.62:35357 requested a full tablet report, sending...
I20260812 06:19:52.364651 14923 ts_manager.cc:194] Registered new tserver with Master: 6d645f7352044b45b631a3eff1fe676b (127.14.139.1:40129)
I20260812 06:19:52.364796 14892 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.027967847s
I20260812 06:19:52.366675 14923 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36494
I20260812 06:19:52.398160 14923 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36510:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:52.445060 15038 tablet_service.cc:1511] Processing CreateTablet for tablet 569db0b081fc492f9d7ca63b0a8a2d2d (DEFAULT_TABLE table=heavy-update-compaction-test [id=2aab891057264f068f5fedd17a1c2c61]), partition=
I20260812 06:19:52.446529 15038 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 569db0b081fc492f9d7ca63b0a8a2d2d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:52.452059 15094 tablet_bootstrap.cc:492] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Bootstrap starting.
I20260812 06:19:52.453181 15094 tablet_bootstrap.cc:654] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:52.457304 15094 tablet_bootstrap.cc:492] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: No bootstrap required, opened a new log
I20260812 06:19:52.457667 15094 ts_tablet_manager.cc:1403] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Time spent bootstrapping tablet: real 0.006s	user 0.004s	sys 0.000s
I20260812 06:19:52.458738 15094 raft_consensus.cc:359] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6d645f7352044b45b631a3eff1fe676b" member_type: VOTER last_known_addr { host: "127.14.139.1" port: 40129 } }
I20260812 06:19:52.458850 15094 raft_consensus.cc:385] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:52.458899 15094 raft_consensus.cc:740] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6d645f7352044b45b631a3eff1fe676b, State: Initialized, Role: FOLLOWER
I20260812 06:19:52.459364 15094 consensus_queue.cc:260] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b [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: "6d645f7352044b45b631a3eff1fe676b" member_type: VOTER last_known_addr { host: "127.14.139.1" port: 40129 } }
I20260812 06:19:52.459547 15094 raft_consensus.cc:399] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:52.459749 15094 raft_consensus.cc:493] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:52.459982 15094 raft_consensus.cc:3060] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:52.462114 15094 raft_consensus.cc:515] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6d645f7352044b45b631a3eff1fe676b" member_type: VOTER last_known_addr { host: "127.14.139.1" port: 40129 } }
I20260812 06:19:52.462502 15094 leader_election.cc:304] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b [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: 6d645f7352044b45b631a3eff1fe676b; no voters: 
I20260812 06:19:52.463052 15094 leader_election.cc:290] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:52.464829 15094 ts_tablet_manager.cc:1434] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Time spent starting tablet: real 0.007s	user 0.004s	sys 0.004s
I20260812 06:19:52.465612 15097 raft_consensus.cc:2804] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:52.465675 15081 heartbeater.cc:499] Master 127.14.139.62:35357 was elected leader, sending a full tablet report...
I20260812 06:19:52.465997 15097 raft_consensus.cc:697] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b [term 1 LEADER]: Becoming Leader. State: Replica: 6d645f7352044b45b631a3eff1fe676b, State: Running, Role: LEADER
I20260812 06:19:52.466148 15097 consensus_queue.cc:237] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b [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: "6d645f7352044b45b631a3eff1fe676b" member_type: VOTER last_known_addr { host: "127.14.139.1" port: 40129 } }
I20260812 06:19:52.471732 14923 catalog_manager.cc:5719] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b reported cstate change: term changed from 0 to 1, leader changed from <none> to 6d645f7352044b45b631a3eff1fe676b (127.14.139.1). New cstate: current_term: 1 leader_uuid: "6d645f7352044b45b631a3eff1fe676b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6d645f7352044b45b631a3eff1fe676b" member_type: VOTER last_known_addr { host: "127.14.139.1" port: 40129 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:52.625820 14892 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.131s	user 0.038s	sys 0.032s
I20260812 06:19:52.837858 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushMRSOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=10.125253
I20260812 06:19:53.142695 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushMRSOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.304s	user 0.225s	sys 0.070s Metrics: {"bytes_written":8902492,"cfile_init":1,"compiler_manager_pool.queue_time_us":483,"delete_count":0,"dirs.queue_time_us":253,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":5666,"drs_written":1,"lbm_read_time_us":134,"lbm_reads_lt_1ms":4,"lbm_write_time_us":71505,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":471,"mutex_wait_us":174,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"spinlock_wait_cycles":477056,"thread_start_us":459,"threads_started":2,"update_count":1085}
I20260812 06:19:53.146766 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling LogGCOp(569db0b081fc492f9d7ca63b0a8a2d2d): free 11976772 bytes of WAL
I20260812 06:19:53.147701 15008 log_reader.cc:385] T 569db0b081fc492f9d7ca63b0a8a2d2d: removed 1 log segments from log reader
I20260812 06:19:53.147782 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000001 (ops 1-6)
I20260812 06:19:53.151254 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: LogGCOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:53.151631 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:53.176745 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.025s	user 0.021s	sys 0.004s Metrics: {"bytes_written":3405230,"delete_count":0,"lbm_write_time_us":11623,"lbm_writes_lt_1ms":86,"reinsert_count":0,"update_count":415}
I20260812 06:19:53.177306 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling UndoDeltaBlockGCOp(569db0b081fc492f9d7ca63b0a8a2d2d): 8206537 bytes on disk
I20260812 06:19:53.178062 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: UndoDeltaBlockGCOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:19:53.178862 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:53.307840 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.129s	user 0.094s	sys 0.033s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487920,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":483,"lbm_read_time_us":7104,"lbm_reads_lt_1ms":360,"lbm_write_time_us":23726,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":246,"threads_started":5,"update_count":1500}
I20260812 06:19:53.308501 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=7.149875
I20260812 06:19:53.330487 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.022s	user 0.015s	sys 0.005s Metrics: {"bytes_written":8943520,"delete_count":0,"lbm_write_time_us":9385,"lbm_writes_lt_1ms":221,"reinsert_count":0,"update_count":1090}
I20260812 06:19:53.330950 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:53.340315 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3364205,"delete_count":0,"lbm_write_time_us":3308,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:19:53.340912 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:53.471256 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.130s	user 0.107s	sys 0.020s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487923,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":473,"lbm_read_time_us":8525,"lbm_reads_lt_1ms":372,"lbm_write_time_us":22703,"lbm_writes_lt_1ms":343,"mutex_wait_us":41,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1500}
I20260812 06:19:53.472101 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=7.149875
I20260812 06:19:53.503208 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.031s	user 0.024s	sys 0.004s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":13427,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:19:53.503643 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:53.515089 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4418,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:53.515534 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:53.620621 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.105s	user 0.078s	sys 0.024s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487926,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":384,"lbm_read_time_us":6400,"lbm_reads_lt_1ms":372,"lbm_write_time_us":19666,"lbm_writes_lt_1ms":343,"mutex_wait_us":69,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:19:53.621109 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=10.126437
I20260812 06:19:53.669677 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.048s	user 0.024s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17976,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:53.670202 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:53.685760 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5788,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.686352 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:53.807479 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.121s	user 0.080s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1685,"lbm_read_time_us":8389,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23336,"lbm_writes_lt_1ms":443,"mutex_wait_us":322,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:53.807950 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=10.126437
I20260812 06:19:53.857645 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.049s	user 0.022s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16518,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:53.858268 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:53.874244 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5991,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.874800 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:54.023016 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.148s	user 0.098s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":710,"lbm_read_time_us":11752,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22891,"lbm_writes_lt_1ms":443,"mutex_wait_us":248,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.023610 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=10.126437
I20260812 06:19:54.070235 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.046s	user 0.028s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16408,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:54.070829 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:54.081423 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3967,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.081998 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:54.208771 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.127s	user 0.092s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":513,"lbm_read_time_us":9320,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25287,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:19:54.209537 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=10.126437
I20260812 06:19:54.249624 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.040s	user 0.024s	sys 0.013s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17285,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:54.250195 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:54.266181 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6237,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.266710 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:54.397801 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.131s	user 0.106s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590349,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":952,"lbm_read_time_us":9504,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26157,"lbm_writes_lt_1ms":443,"mutex_wait_us":253,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24192,"update_count":2000}
I20260812 06:19:54.398413 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=10.126437
I20260812 06:19:54.438802 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.040s	user 0.013s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13987,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:54.439298 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushMRSOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:54.473793 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushMRSOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.034s	user 0.022s	sys 0.005s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1412,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1922,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:54.474714 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling LogGCOp(569db0b081fc492f9d7ca63b0a8a2d2d): free 112239321 bytes of WAL
I20260812 06:19:54.475049 15008 log_reader.cc:385] T 569db0b081fc492f9d7ca63b0a8a2d2d: removed 11 log segments from log reader
I20260812 06:19:54.475250 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000002 (ops 7-11)
I20260812 06:19:54.475318 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000003 (ops 12-16)
I20260812 06:19:54.475374 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000004 (ops 17-21)
I20260812 06:19:54.475412 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000005 (ops 22-26)
I20260812 06:19:54.475462 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000006 (ops 27-31)
I20260812 06:19:54.475498 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000007 (ops 32-36)
I20260812 06:19:54.475533 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000008 (ops 37-41)
I20260812 06:19:54.475570 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000009 (ops 42-46)
I20260812 06:19:54.475638 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000010 (ops 47-50)
I20260812 06:19:54.475688 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000011 (ops 51-55)
I20260812 06:19:54.475733 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000012 (ops 56-60)
I20260812 06:19:54.501585 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: LogGCOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:54.502079 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling UndoDeltaBlockGCOp(569db0b081fc492f9d7ca63b0a8a2d2d): 463 bytes on disk
I20260812 06:19:54.502785 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: UndoDeltaBlockGCOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:19:54.503250 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=6.157687
I20260812 06:19:54.539814 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.036s	user 0.009s	sys 0.013s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":10405,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:54.540380 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling LogGCOp(569db0b081fc492f9d7ca63b0a8a2d2d): free 8767065 bytes of WAL
I20260812 06:19:54.540666 15008 log_reader.cc:385] T 569db0b081fc492f9d7ca63b0a8a2d2d: removed 1 log segments from log reader
I20260812 06:19:54.540712 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000013 (ops 61-65)
I20260812 06:19:54.542397 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: LogGCOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:54.542740 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:54.554441 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4184,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.554945 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:54.748214 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.193s	user 0.140s	sys 0.052s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28795290,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":212,"lbm_read_time_us":11598,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33002,"lbm_writes_lt_1ms":643,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:19:54.749050 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=14.095187
I20260812 06:19:54.817574 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.068s	user 0.031s	sys 0.024s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":26104,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.818127 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:54.829032 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3976,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.829668 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:55.017683 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.188s	user 0.152s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692755,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":920,"lbm_read_time_us":12818,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32564,"lbm_writes_lt_1ms":543,"mutex_wait_us":224,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18176,"update_count":2500}
I20260812 06:19:55.018246 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=14.095187
I20260812 06:19:55.074957 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.057s	user 0.022s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21016,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.075572 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:55.092859 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.017s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6555,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.093463 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:55.281828 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.188s	user 0.137s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":952,"lbm_read_time_us":12885,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33683,"lbm_writes_lt_1ms":543,"mutex_wait_us":342,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:55.282593 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=11.118625
I20260812 06:19:55.330797 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.048s	user 0.022s	sys 0.024s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":18604,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:55.331342 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:55.357599 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.026s	user 0.006s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6162,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:55.358112 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:55.368693 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.010s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3998,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.369297 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:55.564469 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.195s	user 0.138s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692870,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":395,"lbm_read_time_us":13518,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33209,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2500}
I20260812 06:19:55.565282 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=14.095187
I20260812 06:19:55.627645 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.062s	user 0.018s	sys 0.037s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22288,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.628185 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:55.638984 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4050,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.639505 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:55.821372 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.182s	user 0.137s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":294,"lbm_read_time_us":12131,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30513,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:55.822162 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=11.118625
I20260812 06:19:55.856262 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.034s	user 0.023s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15312,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:55.857034 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:55.883239 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.026s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4814,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:55.883701 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:55.894230 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3975,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.894714 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:56.090838 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.196s	user 0.136s	sys 0.047s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692868,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":225,"lbm_read_time_us":12100,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31398,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":34176,"update_count":2500}
I20260812 06:19:56.091631 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=14.095187
I20260812 06:19:56.143227 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.051s	user 0.025s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21698,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.143762 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:56.155511 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4019,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.156093 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushMRSOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:56.190290 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushMRSOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":1623,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1739,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:56.191179 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling LogGCOp(569db0b081fc492f9d7ca63b0a8a2d2d): free 132571365 bytes of WAL
I20260812 06:19:56.191452 15008 log_reader.cc:385] T 569db0b081fc492f9d7ca63b0a8a2d2d: removed 13 log segments from log reader
I20260812 06:19:56.191525 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000014 (ops 66-70)
I20260812 06:19:56.191568 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000015 (ops 71-75)
I20260812 06:19:56.191614 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000016 (ops 76-80)
I20260812 06:19:56.191654 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000017 (ops 81-84)
I20260812 06:19:56.191695 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000018 (ops 85-89)
I20260812 06:19:56.191735 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000019 (ops 90-94)
I20260812 06:19:56.191774 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000020 (ops 95-99)
I20260812 06:19:56.191814 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000021 (ops 100-104)
I20260812 06:19:56.191854 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000022 (ops 105-109)
I20260812 06:19:56.191892 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000023 (ops 110-114)
I20260812 06:19:56.191932 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000024 (ops 115-118)
I20260812 06:19:56.191972 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000025 (ops 119-123)
I20260812 06:19:56.192011 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000026 (ops 124-128)
I20260812 06:19:56.220634 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: LogGCOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.029s	user 0.003s	sys 0.027s Metrics: {}
I20260812 06:19:56.221942 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling UndoDeltaBlockGCOp(569db0b081fc492f9d7ca63b0a8a2d2d): 492 bytes on disk
I20260812 06:19:56.222558 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: UndoDeltaBlockGCOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:56.223126 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=3.181125
I20260812 06:19:56.238051 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.015s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4534,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:56.238488 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:56.248046 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3554,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:56.248483 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:56.472637 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.224s	user 0.171s	sys 0.049s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32897807,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":7611,"lbm_read_time_us":14209,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38814,"lbm_writes_lt_1ms":743,"mutex_wait_us":3681,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":94,"threads_started":1,"update_count":3500}
I20260812 06:19:56.473404 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=15.087375
I20260812 06:19:56.517407 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.044s	user 0.032s	sys 0.011s Metrics: {"bytes_written":16820141,"delete_count":0,"lbm_write_time_us":19449,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:56.518105 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:56.544660 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.026s	user 0.002s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5545,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:56.545197 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:56.556713 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4345,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.557345 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:56.782040 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.224s	user 0.148s	sys 0.069s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28795275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":525,"lbm_read_time_us":14616,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38185,"lbm_writes_lt_1ms":643,"mutex_wait_us":20,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":3000}
I20260812 06:19:56.782618 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=18.063937
I20260812 06:19:56.838763 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.056s	user 0.031s	sys 0.020s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":23909,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:56.839350 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:56.852835 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5368,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.853328 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:57.037055 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.184s	user 0.123s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28795171,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":137,"lbm_read_time_us":13140,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31505,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:57.037765 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=14.095187
I20260812 06:19:57.084404 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.046s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21073,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.084939 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:57.102826 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.018s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6332,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.103317 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:57.271605 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.168s	user 0.114s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":254,"lbm_read_time_us":8829,"lbm_reads_lt_1ms":564,"lbm_write_time_us":34657,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27904,"update_count":2500}
I20260812 06:19:57.272171 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=14.095187
I20260812 06:19:57.340735 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.068s	user 0.033s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25840,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.341246 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:57.351704 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3908,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.352170 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:57.526561 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.174s	user 0.113s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1260,"lbm_read_time_us":12093,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31949,"lbm_writes_lt_1ms":543,"mutex_wait_us":331,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":56448,"update_count":2500}
I20260812 06:19:57.527148 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=11.118625
I20260812 06:19:57.576293 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.048s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18105,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:57.576988 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:57.594185 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.017s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3853,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:57.594653 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:57.605134 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3939,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.605610 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushMRSOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:57.638682 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushMRSOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":1238,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1625,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:57.639420 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling LogGCOp(569db0b081fc492f9d7ca63b0a8a2d2d): free 112692608 bytes of WAL
I20260812 06:19:57.639652 15008 log_reader.cc:385] T 569db0b081fc492f9d7ca63b0a8a2d2d: removed 11 log segments from log reader
I20260812 06:19:57.639696 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000027 (ops 129-133)
I20260812 06:19:57.639745 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000028 (ops 134-138)
I20260812 06:19:57.639791 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000029 (ops 139-143)
I20260812 06:19:57.639854 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000030 (ops 144-148)
I20260812 06:19:57.639892 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000031 (ops 149-153)
I20260812 06:19:57.639933 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000032 (ops 154-158)
I20260812 06:19:57.639971 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000033 (ops 159-163)
I20260812 06:19:57.640008 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000034 (ops 164-168)
I20260812 06:19:57.640046 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000035 (ops 169-173)
I20260812 06:19:57.640084 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000036 (ops 174-178)
I20260812 06:19:57.640121 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000037 (ops 179-183)
I20260812 06:19:57.663976 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: LogGCOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.024s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:19:57.664604 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling UndoDeltaBlockGCOp(569db0b081fc492f9d7ca63b0a8a2d2d): 463 bytes on disk
I20260812 06:19:57.665048 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: UndoDeltaBlockGCOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:19:57.665768 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=3.181125
I20260812 06:19:57.680835 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.015s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4307780,"delete_count":0,"lbm_write_time_us":4351,"lbm_writes_lt_1ms":108,"reinsert_count":0,"update_count":525}
I20260812 06:19:57.681288 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling LogGCOp(569db0b081fc492f9d7ca63b0a8a2d2d): free 12017954 bytes of WAL
I20260812 06:19:57.681489 15008 log_reader.cc:385] T 569db0b081fc492f9d7ca63b0a8a2d2d: removed 1 log segments from log reader
I20260812 06:19:57.681533 15008 log.cc:1079] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/569db0b081fc492f9d7ca63b0a8a2d2d/wal-000000038 (ops 184-188)
I20260812 06:19:57.683840 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: LogGCOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:57.684165 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:57.694949 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.011s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3897533,"delete_count":0,"lbm_write_time_us":3969,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:19:57.695638 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:57.912590 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.217s	user 0.157s	sys 0.053s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32897926,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":338,"lbm_read_time_us":14661,"lbm_reads_lt_1ms":775,"lbm_write_time_us":38730,"lbm_writes_lt_1ms":743,"mutex_wait_us":20,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":76,"threads_started":1,"update_count":3500}
I20260812 06:19:57.914304 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=18.063937
I20260812 06:19:57.980142 14892 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.354s	user 1.945s	sys 0.191s
I20260812 06:19:57.983466 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.069s	user 0.036s	sys 0.019s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":25702,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:57.984175 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=2.188937
I20260812 06:19:57.994048 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: FlushDeltaMemStoresOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3990,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":500}
I20260812 06:19:57.994635 15082 maintenance_manager.cc:419] P 6d645f7352044b45b631a3eff1fe676b: Scheduling MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d): perf score=1.000000
I20260812 06:19:58.074797 14892 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.094s	user 0.004s	sys 0.000s
I20260812 06:19:58.075531 14892 tablet_server.cc:179] TabletServer@127.14.139.1:0 shutting down...
I20260812 06:19:58.146136 15008 maintenance_manager.cc:643] P 6d645f7352044b45b631a3eff1fe676b: MajorDeltaCompactionOp(569db0b081fc492f9d7ca63b0a8a2d2d) complete. Timing: real 0.151s	user 0.123s	sys 0.027s Metrics: {"cfile_cache_hit":100,"cfile_cache_hit_bytes":4066773,"cfile_cache_miss":532,"cfile_cache_miss_bytes":24728401,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":938,"lbm_read_time_us":8633,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31233,"lbm_writes_lt_1ms":643,"mutex_wait_us":32,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":106112,"update_count":3000}
I20260812 06:19:58.146837 14892 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:58.147400 14892 tablet_replica.cc:333] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b: stopping tablet replica
I20260812 06:19:58.147650 14892 raft_consensus.cc:2243] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:58.147898 14892 raft_consensus.cc:2272] T 569db0b081fc492f9d7ca63b0a8a2d2d P 6d645f7352044b45b631a3eff1fe676b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:58.164021 14892 tablet_server.cc:196] TabletServer@127.14.139.1:0 shutdown complete.
I20260812 06:19:58.201764 14892 master.cc:562] Master@127.14.139.62:35357 shutting down...
I20260812 06:19:58.207394 14892 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:58.207597 14892 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:58.207703 14892 tablet_replica.cc:333] T 00000000000000000000000000000000 P 28055ce5f30f4fef8f2a5cea47d70647: stopping tablet replica
I20260812 06:19:58.372485 14892 master.cc:584] Master@127.14.139.62:35357 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6481 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:58.458911 14892 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.14.139.62:38803
I20260812 06:19:58.459319 14892 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:58.461457 15116 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:58.461576 15118 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:58.461709 14892 server_base.cc:1061] running on GCE node
W20260812 06:19:58.461655 15120 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:58.461897 14892 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:58.461946 14892 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:58.461961 14892 hybrid_clock.cc:648] HybridClock initialized: now 1786515598461961 us; error 0 us; skew 500 ppm
I20260812 06:19:58.462867 14892 webserver.cc:533] Webserver started at http://127.14.139.62:33943/ using document root <none> and password file <none>
I20260812 06:19:58.463042 14892 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:58.463114 14892 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:58.463199 14892 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:58.463605 14892 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/master-0-root/instance:
uuid: "2e81b51124454d518fccbac5707c392d"
format_stamp: "Formatted at 2026-08-12 06:19:58 on dist-test-slave-8n49"
I20260812 06:19:58.465435 14892 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:58.466389 15126 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:58.466691 14892 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:58.466758 14892 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/master-0-root
uuid: "2e81b51124454d518fccbac5707c392d"
format_stamp: "Formatted at 2026-08-12 06:19:58 on dist-test-slave-8n49"
I20260812 06:19:58.466856 14892 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:58.484153 14892 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:58.484659 14892 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:58.488827 14892 rpc_server.cc:307] RPC server started. Bound to: 127.14.139.62:38803
I20260812 06:19:58.491602 15190 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.139.62:38803 every 8 connection(s)
I20260812 06:19:58.492596 15191 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:58.499878 15191 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d: Bootstrap starting.
I20260812 06:19:58.500682 15191 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:58.501706 15191 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d: No bootstrap required, opened a new log
I20260812 06:19:58.502054 15191 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2e81b51124454d518fccbac5707c392d" member_type: VOTER }
I20260812 06:19:58.502138 15191 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:58.502161 15191 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2e81b51124454d518fccbac5707c392d, State: Initialized, Role: FOLLOWER
I20260812 06:19:58.502267 15191 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [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: "2e81b51124454d518fccbac5707c392d" member_type: VOTER }
I20260812 06:19:58.502323 15191 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:58.502347 15191 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:58.502382 15191 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:58.503026 15191 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2e81b51124454d518fccbac5707c392d" member_type: VOTER }
I20260812 06:19:58.503137 15191 leader_election.cc:304] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [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: 2e81b51124454d518fccbac5707c392d; no voters: 
I20260812 06:19:58.503288 15191 leader_election.cc:290] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:58.503491 15194 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:58.503753 15194 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [term 1 LEADER]: Becoming Leader. State: Replica: 2e81b51124454d518fccbac5707c392d, State: Running, Role: LEADER
I20260812 06:19:58.503890 15194 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [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: "2e81b51124454d518fccbac5707c392d" member_type: VOTER }
I20260812 06:19:58.503943 15191 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:58.504366 15195 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2e81b51124454d518fccbac5707c392d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2e81b51124454d518fccbac5707c392d" member_type: VOTER } }
I20260812 06:19:58.504413 15197 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2e81b51124454d518fccbac5707c392d. Latest consensus state: current_term: 1 leader_uuid: "2e81b51124454d518fccbac5707c392d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2e81b51124454d518fccbac5707c392d" member_type: VOTER } }
I20260812 06:19:58.504520 15195 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:58.504537 15197 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:58.505048 15201 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:58.505985 15201 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:58.506223 14892 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:58.507853 15201 catalog_manager.cc:1383] Generated new cluster ID: f3a8f6edbb1b42d2a15c1980fc015101
I20260812 06:19:58.507912 15201 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:58.518702 15201 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:58.519280 15201 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:58.524533 15201 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d: Generated new TSK 0
I20260812 06:19:58.524746 15201 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:58.538725 14892 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:58.540733 15215 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:58.540861 15218 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:58.540953 15216 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:58.541074 14892 server_base.cc:1061] running on GCE node
I20260812 06:19:58.541298 14892 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:58.541339 14892 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:58.541354 14892 hybrid_clock.cc:648] HybridClock initialized: now 1786515598541354 us; error 0 us; skew 500 ppm
I20260812 06:19:58.542201 14892 webserver.cc:533] Webserver started at http://127.14.139.1:46337/ using document root <none> and password file <none>
I20260812 06:19:58.542379 14892 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:58.542450 14892 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:58.542529 14892 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:58.542922 14892 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/instance:
uuid: "7112fb7949534113a65f1b058f7422c7"
format_stamp: "Formatted at 2026-08-12 06:19:58 on dist-test-slave-8n49"
I20260812 06:19:58.544441 14892 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:58.545369 15223 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:58.545632 14892 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:58.545696 14892 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root
uuid: "7112fb7949534113a65f1b058f7422c7"
format_stamp: "Formatted at 2026-08-12 06:19:58 on dist-test-slave-8n49"
I20260812 06:19:58.545792 14892 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:58.551947 14892 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:58.552332 14892 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:58.552708 14892 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:58.553169 14892 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:58.553205 14892 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:58.553236 14892 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:58.553296 14892 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:58.557561 14892 rpc_server.cc:307] RPC server started. Bound to: 127.14.139.1:41341
I20260812 06:19:58.558434 15295 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.139.1:41341 every 8 connection(s)
I20260812 06:19:58.566506 15297 heartbeater.cc:344] Connected to a master server at 127.14.139.62:38803
I20260812 06:19:58.566644 15297 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:58.566910 15297 heartbeater.cc:507] Master 127.14.139.62:38803 requested a full tablet report, sending...
I20260812 06:19:58.567647 15148 ts_manager.cc:194] Registered new tserver with Master: 7112fb7949534113a65f1b058f7422c7 (127.14.139.1:41341)
I20260812 06:19:58.568424 14892 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009986144s
I20260812 06:19:58.568431 15148 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49378
I20260812 06:19:58.576114 15148 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49388:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:58.585143 15253 tablet_service.cc:1511] Processing CreateTablet for tablet 1bee4e6c77dd4161a1d61896b176a9d1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=43c0cbfe9d2e40379bc0e867a74920a5]), partition=
I20260812 06:19:58.585402 15253 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 1bee4e6c77dd4161a1d61896b176a9d1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:58.587512 15313 tablet_bootstrap.cc:492] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Bootstrap starting.
I20260812 06:19:58.588244 15313 tablet_bootstrap.cc:654] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:58.589373 15313 tablet_bootstrap.cc:492] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: No bootstrap required, opened a new log
I20260812 06:19:58.589499 15313 ts_tablet_manager.cc:1403] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:58.589937 15313 raft_consensus.cc:359] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7112fb7949534113a65f1b058f7422c7" member_type: VOTER last_known_addr { host: "127.14.139.1" port: 41341 } }
I20260812 06:19:58.590073 15313 raft_consensus.cc:385] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:58.590122 15313 raft_consensus.cc:740] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7112fb7949534113a65f1b058f7422c7, State: Initialized, Role: FOLLOWER
I20260812 06:19:58.590292 15313 consensus_queue.cc:260] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7 [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: "7112fb7949534113a65f1b058f7422c7" member_type: VOTER last_known_addr { host: "127.14.139.1" port: 41341 } }
I20260812 06:19:58.590400 15313 raft_consensus.cc:399] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:58.590454 15313 raft_consensus.cc:493] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:58.590512 15313 raft_consensus.cc:3060] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:58.591202 15313 raft_consensus.cc:515] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7112fb7949534113a65f1b058f7422c7" member_type: VOTER last_known_addr { host: "127.14.139.1" port: 41341 } }
I20260812 06:19:58.591317 15313 leader_election.cc:304] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7 [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: 7112fb7949534113a65f1b058f7422c7; no voters: 
I20260812 06:19:58.591472 15313 leader_election.cc:290] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:58.591604 15315 raft_consensus.cc:2804] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:58.591847 15315 raft_consensus.cc:697] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7 [term 1 LEADER]: Becoming Leader. State: Replica: 7112fb7949534113a65f1b058f7422c7, State: Running, Role: LEADER
I20260812 06:19:58.591903 15297 heartbeater.cc:499] Master 127.14.139.62:38803 was elected leader, sending a full tablet report...
I20260812 06:19:58.592036 15315 consensus_queue.cc:237] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7 [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: "7112fb7949534113a65f1b058f7422c7" member_type: VOTER last_known_addr { host: "127.14.139.1" port: 41341 } }
I20260812 06:19:58.591881 15313 ts_tablet_manager.cc:1434] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:58.593644 15148 catalog_manager.cc:5719] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7 reported cstate change: term changed from 0 to 1, leader changed from <none> to 7112fb7949534113a65f1b058f7422c7 (127.14.139.1). New cstate: current_term: 1 leader_uuid: "7112fb7949534113a65f1b058f7422c7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7112fb7949534113a65f1b058f7422c7" member_type: VOTER last_known_addr { host: "127.14.139.1" port: 41341 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:58.652853 14892 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.022s	sys 0.000s
I20260812 06:19:58.809022 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushMRSOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=19.054940
I20260812 06:19:58.958863 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushMRSOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.150s	user 0.111s	sys 0.037s Metrics: {"bytes_written":12307489,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":959,"drs_written":1,"lbm_read_time_us":121,"lbm_reads_lt_1ms":4,"lbm_write_time_us":35428,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:19:58.959565 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling LogGCOp(1bee4e6c77dd4161a1d61896b176a9d1): free 20743880 bytes of WAL
I20260812 06:19:58.959808 15229 log_reader.cc:385] T 1bee4e6c77dd4161a1d61896b176a9d1: removed 2 log segments from log reader
I20260812 06:19:58.959880 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000001 (ops 1-6)
I20260812 06:19:58.959970 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000002 (ops 7-11)
I20260812 06:19:58.964226 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: LogGCOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:58.964617 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:19:58.980723 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.016s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4202,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.981138 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling UndoDeltaBlockGCOp(1bee4e6c77dd4161a1d61896b176a9d1): 16411393 bytes on disk
I20260812 06:19:58.981513 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: UndoDeltaBlockGCOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:19:58.981863 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:19:58.991843 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3791,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.992246 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:19:59.185509 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.193s	user 0.121s	sys 0.069s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774806,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":596,"lbm_read_time_us":13844,"lbm_reads_lt_1ms":569,"lbm_write_time_us":32846,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"thread_start_us":323,"threads_started":5,"update_count":2500}
I20260812 06:19:59.186139 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=14.095187
I20260812 06:19:59.243383 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.057s	user 0.018s	sys 0.036s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25079,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.243834 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:19:59.255273 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3924,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.255761 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:19:59.464372 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.208s	user 0.117s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":701,"lbm_read_time_us":13365,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32431,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:19:59.465121 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=14.095187
I20260812 06:19:59.530653 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.065s	user 0.027s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24216,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.531417 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:19:59.544174 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4623,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.545059 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:19:59.728888 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.184s	user 0.120s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":249,"lbm_read_time_us":13150,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29681,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2500}
I20260812 06:19:59.729585 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=14.095187
I20260812 06:19:59.792845 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.063s	user 0.028s	sys 0.029s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24487,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.793443 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:19:59.807505 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5102,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.807983 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:19:59.992805 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.185s	user 0.141s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":368,"lbm_read_time_us":12893,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29309,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2500}
I20260812 06:19:59.993369 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=14.095187
I20260812 06:20:00.061393 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.067s	user 0.039s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23967,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.062031 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:20:00.074330 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4585,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.074908 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:20:00.257947 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.183s	user 0.115s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":387,"lbm_read_time_us":13597,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29304,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:00.258404 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=11.118625
I20260812 06:20:00.294237 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.036s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15488,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:00.295151 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:20:00.311703 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6565,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:00.312227 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushMRSOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:20:00.377399 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushMRSOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.065s	user 0.039s	sys 0.001s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":285,"dirs.run_wall_time_us":1710,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1807,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:00.378157 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling LogGCOp(1bee4e6c77dd4161a1d61896b176a9d1): free 115943173 bytes of WAL
I20260812 06:20:00.378409 15229 log_reader.cc:385] T 1bee4e6c77dd4161a1d61896b176a9d1: removed 11 log segments from log reader
I20260812 06:20:00.378479 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000003 (ops 12-16)
I20260812 06:20:00.378542 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000004 (ops 17-21)
I20260812 06:20:00.378600 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000005 (ops 22-26)
I20260812 06:20:00.378643 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000006 (ops 27-31)
I20260812 06:20:00.378680 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000007 (ops 32-36)
I20260812 06:20:00.378722 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000008 (ops 37-41)
I20260812 06:20:00.378760 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000009 (ops 42-46)
I20260812 06:20:00.378800 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000010 (ops 47-51)
I20260812 06:20:00.378839 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000011 (ops 52-56)
I20260812 06:20:00.378878 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000012 (ops 57-61)
I20260812 06:20:00.378917 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000013 (ops 62-66)
I20260812 06:20:00.403821 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: LogGCOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:00.404331 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling UndoDeltaBlockGCOp(1bee4e6c77dd4161a1d61896b176a9d1): 472 bytes on disk
I20260812 06:20:00.404963 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: UndoDeltaBlockGCOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:20:00.405604 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=7.149875
I20260812 06:20:00.433450 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.028s	user 0.019s	sys 0.007s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":11657,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:20:00.433987 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling LogGCOp(1bee4e6c77dd4161a1d61896b176a9d1): free 8767118 bytes of WAL
I20260812 06:20:00.434243 15229 log_reader.cc:385] T 1bee4e6c77dd4161a1d61896b176a9d1: removed 1 log segments from log reader
I20260812 06:20:00.434317 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000014 (ops 67-71)
I20260812 06:20:00.436075 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: LogGCOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:00.436396 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:20:00.449405 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4724,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:00.449891 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:20:00.693536 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.243s	user 0.153s	sys 0.078s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979734,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":820,"lbm_read_time_us":14321,"lbm_reads_lt_1ms":766,"lbm_write_time_us":38866,"lbm_writes_lt_1ms":743,"mutex_wait_us":62,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10752,"thread_start_us":116,"threads_started":1,"update_count":3500}
I20260812 06:20:00.694288 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=18.063937
I20260812 06:20:00.768509 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.074s	user 0.039s	sys 0.028s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":33059,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:20:00.769032 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:20:00.780753 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4109,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.781243 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:20:01.003681 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.222s	user 0.130s	sys 0.077s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":866,"lbm_read_time_us":13815,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33469,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":3000}
I20260812 06:20:01.004395 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=18.063937
I20260812 06:20:01.070783 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.066s	user 0.028s	sys 0.033s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":29279,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:20:01.071309 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:20:01.082875 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4000,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.083725 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:20:01.299242 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.215s	user 0.154s	sys 0.055s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":226,"lbm_read_time_us":14894,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34741,"lbm_writes_lt_1ms":643,"mutex_wait_us":59,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":64000,"update_count":3000}
I20260812 06:20:01.300025 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=18.063937
I20260812 06:20:01.368096 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.068s	user 0.035s	sys 0.023s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":29541,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:20:01.368671 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:20:01.383206 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5329,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.383845 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:20:01.598462 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.214s	user 0.143s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877106,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":313,"lbm_read_time_us":15152,"lbm_reads_lt_1ms":672,"lbm_write_time_us":38537,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19328,"update_count":3000}
I20260812 06:20:01.599231 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=15.087375
I20260812 06:20:01.645167 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.046s	user 0.022s	sys 0.023s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":19838,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:01.645736 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:20:01.669145 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.023s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5824,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:01.669770 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:20:01.680611 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4120,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.681089 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:20:01.893925 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.212s	user 0.149s	sys 0.059s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877208,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":787,"lbm_read_time_us":14642,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33128,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20480,"update_count":3000}
I20260812 06:20:01.895632 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=15.087375
I20260812 06:20:01.958151 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.062s	user 0.037s	sys 0.019s Metrics: {"bytes_written":17722676,"delete_count":0,"lbm_write_time_us":24164,"lbm_writes_lt_1ms":435,"reinsert_count":0,"update_count":2160}
I20260812 06:20:01.958674 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=5.165500
I20260812 06:20:01.982615 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.024s	user 0.011s	sys 0.007s Metrics: {"bytes_written":6892309,"delete_count":0,"lbm_write_time_us":8723,"lbm_writes_lt_1ms":171,"reinsert_count":0,"update_count":840}
I20260812 06:20:01.983194 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushMRSOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:20:02.035617 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushMRSOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.052s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1357580,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1614,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2039,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:20:02.036291 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling LogGCOp(1bee4e6c77dd4161a1d61896b176a9d1): free 128867416 bytes of WAL
I20260812 06:20:02.036589 15229 log_reader.cc:385] T 1bee4e6c77dd4161a1d61896b176a9d1: removed 13 log segments from log reader
I20260812 06:20:02.036649 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000015 (ops 72-76)
I20260812 06:20:02.036681 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000016 (ops 77-80)
I20260812 06:20:02.036741 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000017 (ops 81-85)
I20260812 06:20:02.036785 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000018 (ops 86-90)
I20260812 06:20:02.036826 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000019 (ops 91-95)
I20260812 06:20:02.036866 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000020 (ops 96-100)
I20260812 06:20:02.036906 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000021 (ops 101-105)
I20260812 06:20:02.036944 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000022 (ops 106-110)
I20260812 06:20:02.036988 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000023 (ops 111-114)
I20260812 06:20:02.037026 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000024 (ops 115-119)
I20260812 06:20:02.037068 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000025 (ops 120-124)
I20260812 06:20:02.037108 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000026 (ops 125-128)
I20260812 06:20:02.037133 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000027 (ops 129-133)
I20260812 06:20:02.064347 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: LogGCOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.028s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:20:02.064886 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling UndoDeltaBlockGCOp(1bee4e6c77dd4161a1d61896b176a9d1): 508 bytes on disk
I20260812 06:20:02.065299 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: UndoDeltaBlockGCOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:20:02.065788 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=7.149875
I20260812 06:20:02.090488 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.025s	user 0.010s	sys 0.012s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":10330,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:20:02.091068 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling LogGCOp(1bee4e6c77dd4161a1d61896b176a9d1): free 12018013 bytes of WAL
I20260812 06:20:02.091306 15229 log_reader.cc:385] T 1bee4e6c77dd4161a1d61896b176a9d1: removed 1 log segments from log reader
I20260812 06:20:02.091352 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000028 (ops 134-138)
I20260812 06:20:02.093820 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: LogGCOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:02.094147 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:20:02.110932 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.017s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4645,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.111397 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:20:02.362246 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.251s	user 0.150s	sys 0.100s Metrics: {"cfile_cache_miss":934,"cfile_cache_miss_bytes":41184573,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":339,"lbm_read_time_us":17248,"lbm_reads_lt_1ms":966,"lbm_write_time_us":46006,"lbm_writes_lt_1ms":943,"mutex_wait_us":48,"peak_mem_usage":112822188,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":79,"threads_started":1,"update_count":4500}
I20260812 06:20:02.363024 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=22.032687
I20260812 06:20:02.432436 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.069s	user 0.039s	sys 0.024s Metrics: {"bytes_written":24614721,"delete_count":0,"lbm_write_time_us":29399,"lbm_writes_lt_1ms":603,"reinsert_count":0,"update_count":3000}
I20260812 06:20:02.433112 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:20:02.460041 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.027s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5151,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.460613 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:20:02.471657 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4332,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.472126 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:20:02.679495 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.207s	user 0.156s	sys 0.048s Metrics: {"cfile_cache_miss":833,"cfile_cache_miss_bytes":37082039,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":148,"lbm_read_time_us":15746,"lbm_reads_lt_1ms":873,"lbm_write_time_us":43621,"lbm_writes_lt_1ms":843,"mutex_wait_us":30,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":4000}
I20260812 06:20:02.680150 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=18.063937
I20260812 06:20:02.737715 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.057s	user 0.026s	sys 0.028s Metrics: {"bytes_written":20512321,"delete_count":0,"lbm_write_time_us":24922,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:02.738214 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:20:02.750504 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4095,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.751272 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:20:02.913225 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.162s	user 0.113s	sys 0.048s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877108,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1002,"lbm_read_time_us":10884,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32432,"lbm_writes_lt_1ms":643,"mutex_wait_us":287,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":3000}
I20260812 06:20:02.913996 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=14.095187
I20260812 06:20:02.957209 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.043s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18922,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.957760 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:20:02.968019 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3970,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.968483 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:20:03.135804 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.167s	user 0.118s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":490,"lbm_read_time_us":10255,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31071,"lbm_writes_lt_1ms":543,"mutex_wait_us":145,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2500}
I20260812 06:20:03.136464 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=14.095187
I20260812 06:20:03.175123 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.038s	user 0.022s	sys 0.014s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17564,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.175732 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:20:03.339871 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.164s	user 0.107s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672160,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":690,"lbm_read_time_us":11075,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24443,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2000}
I20260812 06:20:03.340653 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=14.095187
I20260812 06:20:03.395550 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.055s	user 0.018s	sys 0.034s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25377,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.396131 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:20:03.411615 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6188,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.412209 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushMRSOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:20:03.444201 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushMRSOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.032s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1545,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1520,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:03.445016 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling LogGCOp(1bee4e6c77dd4161a1d61896b176a9d1): free 112692556 bytes of WAL
I20260812 06:20:03.445264 15229 log_reader.cc:385] T 1bee4e6c77dd4161a1d61896b176a9d1: removed 11 log segments from log reader
I20260812 06:20:03.445338 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000029 (ops 139-143)
I20260812 06:20:03.445391 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000030 (ops 144-148)
I20260812 06:20:03.445451 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000031 (ops 149-153)
I20260812 06:20:03.445490 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000032 (ops 154-158)
I20260812 06:20:03.445525 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000033 (ops 159-163)
I20260812 06:20:03.445560 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000034 (ops 164-168)
I20260812 06:20:03.445597 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000035 (ops 169-173)
I20260812 06:20:03.445633 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000036 (ops 174-178)
I20260812 06:20:03.445670 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000037 (ops 179-183)
I20260812 06:20:03.445708 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000038 (ops 184-188)
I20260812 06:20:03.445742 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000039 (ops 189-193)
I20260812 06:20:03.471590 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: LogGCOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.026s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:20:03.472152 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling UndoDeltaBlockGCOp(1bee4e6c77dd4161a1d61896b176a9d1): 472 bytes on disk
I20260812 06:20:03.472787 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: UndoDeltaBlockGCOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":163,"lbm_reads_lt_1ms":4}
I20260812 06:20:03.473601 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=3.181125
I20260812 06:20:03.498685 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.025s	user 0.006s	sys 0.006s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":5524,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:03.499261 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling LogGCOp(1bee4e6c77dd4161a1d61896b176a9d1): free 12018006 bytes of WAL
I20260812 06:20:03.499509 15229 log_reader.cc:385] T 1bee4e6c77dd4161a1d61896b176a9d1: removed 1 log segments from log reader
I20260812 06:20:03.499577 15229 log.cc:1079] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: Deleting log segment in path: /tmp/dist-test-taskAuWI15/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515591955169-14892-0/minicluster-data/ts-0-root/wals/1bee4e6c77dd4161a1d61896b176a9d1/wal-000000040 (ops 194-198)
I20260812 06:20:03.502199 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: LogGCOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:03.502614 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=2.188937
I20260812 06:20:03.512662 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: FlushDeltaMemStoresOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.010s	user 0.001s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3700,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:03.513132 15298 maintenance_manager.cc:419] P 7112fb7949534113a65f1b058f7422c7: Scheduling MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1): perf score=1.000000
I20260812 06:20:03.547307 14892 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.894s	user 1.852s	sys 0.160s
I20260812 06:20:03.654588 14892 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.107s	user 0.002s	sys 0.000s
I20260812 06:20:03.655225 14892 tablet_server.cc:179] TabletServer@127.14.139.1:0 shutting down...
I20260812 06:20:03.715164 15229 maintenance_manager.cc:643] P 7112fb7949534113a65f1b058f7422c7: MajorDeltaCompactionOp(1bee4e6c77dd4161a1d61896b176a9d1) complete. Timing: real 0.202s	user 0.148s	sys 0.053s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979735,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":514,"lbm_read_time_us":15768,"lbm_reads_lt_1ms":770,"lbm_write_time_us":34200,"lbm_writes_lt_1ms":743,"mutex_wait_us":21,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17536,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:20:03.715929 14892 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:03.716342 14892 tablet_replica.cc:333] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7: stopping tablet replica
I20260812 06:20:03.716497 14892 raft_consensus.cc:2243] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:03.716722 14892 raft_consensus.cc:2272] T 1bee4e6c77dd4161a1d61896b176a9d1 P 7112fb7949534113a65f1b058f7422c7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:03.731559 14892 tablet_server.cc:196] TabletServer@127.14.139.1:0 shutdown complete.
I20260812 06:20:03.773898 14892 master.cc:562] Master@127.14.139.62:38803 shutting down...
I20260812 06:20:03.777321 14892 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:03.777534 14892 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:03.777619 14892 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2e81b51124454d518fccbac5707c392d: stopping tablet replica
I20260812 06:20:03.789938 14892 master.cc:584] Master@127.14.139.62:38803 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5410 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11894 ms total)

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