[==========] 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:17:52.634521  7702 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.7.133.190:39723
I20260812 06:17:52.635565  7702 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:17:52.636202  7702 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:52.643072  7707 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:17:52.643196  7702 server_base.cc:1061] running on GCE node
W20260812 06:17:52.643427  7708 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:52.643643  7710 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:17:52.644407  7702 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:52.644538  7702 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:17:52.644641  7702 hybrid_clock.cc:648] HybridClock initialized: now 1786515472644637 us; error 0 us; skew 500 ppm
I20260812 06:17:52.646948  7702 webserver.cc:533] Webserver started at http://127.7.133.190:35327/ using document root <none> and password file <none>
I20260812 06:17:52.647600  7702 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:52.647738  7702 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:52.648034  7702 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:52.650043  7702 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/master-0-root/instance:
uuid: "0f4f5321adf94665b2eb5ee9ba304993"
format_stamp: "Formatted at 2026-08-12 06:17:52 on dist-test-slave-8n49"
I20260812 06:17:52.654733  7702 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.001s	sys 0.004s
I20260812 06:17:52.657624  7716 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:17:52.658838  7702 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.002s	sys 0.001s
I20260812 06:17:52.659003  7702 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/master-0-root
uuid: "0f4f5321adf94665b2eb5ee9ba304993"
format_stamp: "Formatted at 2026-08-12 06:17:52 on dist-test-slave-8n49"
I20260812 06:17:52.659142  7702 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-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:17:52.671238  7702 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:52.671901  7702 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:17:52.672087  7702 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:52.680190  7782 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.133.190:39723 every 8 connection(s)
I20260812 06:17:52.680187  7702 rpc_server.cc:307] RPC server started. Bound to: 127.7.133.190:39723
I20260812 06:17:52.682638  7783 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:17:52.688844  7783 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993: Bootstrap starting.
I20260812 06:17:52.691543  7783 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:52.692637  7783 log.cc:826] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:52.694802  7783 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993: No bootstrap required, opened a new log
I20260812 06:17:52.698021  7783 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0f4f5321adf94665b2eb5ee9ba304993" member_type: VOTER }
I20260812 06:17:52.698203  7783 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:52.698305  7783 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0f4f5321adf94665b2eb5ee9ba304993, State: Initialized, Role: FOLLOWER
I20260812 06:17:52.698969  7783 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [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: "0f4f5321adf94665b2eb5ee9ba304993" member_type: VOTER }
I20260812 06:17:52.699149  7783 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:52.699235  7783 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:52.699431  7783 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:52.700368  7783 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0f4f5321adf94665b2eb5ee9ba304993" member_type: VOTER }
I20260812 06:17:52.700894  7783 leader_election.cc:304] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [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: 0f4f5321adf94665b2eb5ee9ba304993; no voters: 
I20260812 06:17:52.701282  7783 leader_election.cc:290] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:52.701471  7788 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:52.701745  7788 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [term 1 LEADER]: Becoming Leader. State: Replica: 0f4f5321adf94665b2eb5ee9ba304993, State: Running, Role: LEADER
I20260812 06:17:52.702235  7788 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [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: "0f4f5321adf94665b2eb5ee9ba304993" member_type: VOTER }
I20260812 06:17:52.702491  7783 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:52.704316  7789 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0f4f5321adf94665b2eb5ee9ba304993" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0f4f5321adf94665b2eb5ee9ba304993" member_type: VOTER } }
I20260812 06:17:52.704248  7791 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0f4f5321adf94665b2eb5ee9ba304993. Latest consensus state: current_term: 1 leader_uuid: "0f4f5321adf94665b2eb5ee9ba304993" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0f4f5321adf94665b2eb5ee9ba304993" member_type: VOTER } }
I20260812 06:17:52.704409  7789 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:52.704420  7791 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:52.704836  7800 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:52.707464  7800 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:52.707734  7702 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:52.712281  7800 catalog_manager.cc:1383] Generated new cluster ID: 516129e66b3345e382e8e17b96c6e4f9
I20260812 06:17:52.712357  7800 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:52.739954  7800 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:52.741200  7800 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:52.748965  7800 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993: Generated new TSK 0
I20260812 06:17:52.749747  7800 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:52.773000  7702 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:52.776261  7811 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:52.776429  7810 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:17:52.776531  7814 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:17:52.776707  7702 server_base.cc:1061] running on GCE node
I20260812 06:17:52.776980  7702 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:52.777041  7702 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:17:52.777065  7702 hybrid_clock.cc:648] HybridClock initialized: now 1786515472777065 us; error 0 us; skew 500 ppm
I20260812 06:17:52.778155  7702 webserver.cc:533] Webserver started at http://127.7.133.129:34709/ using document root <none> and password file <none>
I20260812 06:17:52.778337  7702 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:52.778398  7702 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:52.778471  7702 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:52.778945  7702 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/instance:
uuid: "aefa07cfa3734999a2a3a5d96cae6f6a"
format_stamp: "Formatted at 2026-08-12 06:17:52 on dist-test-slave-8n49"
I20260812 06:17:52.780946  7702 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:17:52.782231  7822 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:17:52.782594  7702 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:52.782687  7702 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root
uuid: "aefa07cfa3734999a2a3a5d96cae6f6a"
format_stamp: "Formatted at 2026-08-12 06:17:52 on dist-test-slave-8n49"
I20260812 06:17:52.782796  7702 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-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:17:52.803639  7702 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:52.804214  7702 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:52.805439  7702 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:52.807406  7702 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:52.807555  7702 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:52.807663  7702 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:52.807711  7702 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:52.817075  7702 rpc_server.cc:307] RPC server started. Bound to: 127.7.133.129:32825
I20260812 06:17:52.817273  7891 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.133.129:32825 every 8 connection(s)
I20260812 06:17:52.834666  7892 heartbeater.cc:344] Connected to a master server at 127.7.133.190:39723
I20260812 06:17:52.835003  7892 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:52.835636  7892 heartbeater.cc:507] Master 127.7.133.190:39723 requested a full tablet report, sending...
I20260812 06:17:52.837934  7737 ts_manager.cc:194] Registered new tserver with Master: aefa07cfa3734999a2a3a5d96cae6f6a (127.7.133.129:32825)
I20260812 06:17:52.838091  7702 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.020276731s
I20260812 06:17:52.840148  7737 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51602
I20260812 06:17:52.849754  7737 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51614:
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:17:52.866034  7853 tablet_service.cc:1511] Processing CreateTablet for tablet a1b4b509787841deadf7146518e0e6f1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=08f55d93e45b4647968e312992631c40]), partition=
I20260812 06:17:52.866536  7853 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a1b4b509787841deadf7146518e0e6f1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:52.869158  7908 tablet_bootstrap.cc:492] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Bootstrap starting.
I20260812 06:17:52.870599  7908 tablet_bootstrap.cc:654] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:52.871891  7908 tablet_bootstrap.cc:492] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: No bootstrap required, opened a new log
I20260812 06:17:52.872040  7908 ts_tablet_manager.cc:1403] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:52.872663  7908 raft_consensus.cc:359] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aefa07cfa3734999a2a3a5d96cae6f6a" member_type: VOTER last_known_addr { host: "127.7.133.129" port: 32825 } }
I20260812 06:17:52.872816  7908 raft_consensus.cc:385] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:52.872967  7908 raft_consensus.cc:740] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: aefa07cfa3734999a2a3a5d96cae6f6a, State: Initialized, Role: FOLLOWER
I20260812 06:17:52.873160  7908 consensus_queue.cc:260] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a [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: "aefa07cfa3734999a2a3a5d96cae6f6a" member_type: VOTER last_known_addr { host: "127.7.133.129" port: 32825 } }
I20260812 06:17:52.873284  7908 raft_consensus.cc:399] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:52.873409  7908 raft_consensus.cc:493] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:52.873488  7908 raft_consensus.cc:3060] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:52.874322  7908 raft_consensus.cc:515] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aefa07cfa3734999a2a3a5d96cae6f6a" member_type: VOTER last_known_addr { host: "127.7.133.129" port: 32825 } }
I20260812 06:17:52.874511  7908 leader_election.cc:304] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a [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: aefa07cfa3734999a2a3a5d96cae6f6a; no voters: 
I20260812 06:17:52.874782  7908 leader_election.cc:290] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:52.874903  7910 raft_consensus.cc:2804] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:52.875205  7908 ts_tablet_manager.cc:1434] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Time spent starting tablet: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:17:52.875465  7892 heartbeater.cc:499] Master 127.7.133.190:39723 was elected leader, sending a full tablet report...
I20260812 06:17:52.875207  7910 raft_consensus.cc:697] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a [term 1 LEADER]: Becoming Leader. State: Replica: aefa07cfa3734999a2a3a5d96cae6f6a, State: Running, Role: LEADER
I20260812 06:17:52.875926  7910 consensus_queue.cc:237] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a [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: "aefa07cfa3734999a2a3a5d96cae6f6a" member_type: VOTER last_known_addr { host: "127.7.133.129" port: 32825 } }
I20260812 06:17:52.879011  7736 catalog_manager.cc:5719] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a reported cstate change: term changed from 0 to 1, leader changed from <none> to aefa07cfa3734999a2a3a5d96cae6f6a (127.7.133.129). New cstate: current_term: 1 leader_uuid: "aefa07cfa3734999a2a3a5d96cae6f6a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aefa07cfa3734999a2a3a5d96cae6f6a" member_type: VOTER last_known_addr { host: "127.7.133.129" port: 32825 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:52.945114  7702 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.020s	sys 0.004s
I20260812 06:17:53.068495  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushMRSOp(a1b4b509787841deadf7146518e0e6f1): perf score=15.086190
I20260812 06:17:53.232921  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushMRSOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.164s	user 0.135s	sys 0.028s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":215,"delete_count":0,"dirs.queue_time_us":39,"dirs.run_cpu_time_us":261,"dirs.run_wall_time_us":928,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40146,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":1280,"thread_start_us":139,"threads_started":1,"update_count":1500}
I20260812 06:17:53.234287  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling LogGCOp(a1b4b509787841deadf7146518e0e6f1): free 8725963 bytes of WAL
I20260812 06:17:53.234606  7827 log_reader.cc:385] T a1b4b509787841deadf7146518e0e6f1: removed 1 log segments from log reader
I20260812 06:17:53.234673  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000001 (ops 1-6)
I20260812 06:17:53.237144  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: LogGCOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:53.237617  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling UndoDeltaBlockGCOp(a1b4b509787841deadf7146518e0e6f1): 12308958 bytes on disk
I20260812 06:17:53.238448  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: UndoDeltaBlockGCOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4}
I20260812 06:17:53.239053  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:53.256659  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.017s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5961,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.257241  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:53.404774  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.147s	user 0.114s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":778,"lbm_read_time_us":7804,"lbm_reads_lt_1ms":460,"lbm_write_time_us":29384,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":403,"threads_started":5,"update_count":2000}
I20260812 06:17:53.405604  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=10.126437
I20260812 06:17:53.447230  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.041s	user 0.022s	sys 0.014s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17134,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:53.447755  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:53.459579  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4163,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.460271  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:53.591861  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.131s	user 0.099s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1064,"lbm_read_time_us":8807,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25702,"lbm_writes_lt_1ms":443,"mutex_wait_us":97,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19072,"update_count":2000}
I20260812 06:17:53.592656  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=10.126437
I20260812 06:17:53.643344  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.051s	user 0.026s	sys 0.020s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":19208,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:53.643889  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:53.656224  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4816,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.656879  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:53.778610  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.121s	user 0.090s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1024,"lbm_read_time_us":8444,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22852,"lbm_writes_lt_1ms":443,"mutex_wait_us":347,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2000}
I20260812 06:17:53.779351  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=10.126437
I20260812 06:17:53.825417  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.046s	user 0.034s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15839,"lbm_writes_lt_1ms":303,"mutex_wait_us":20,"reinsert_count":0,"update_count":1500}
I20260812 06:17:53.825991  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:53.836917  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4129,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.837380  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:54.029142  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.192s	user 0.123s	sys 0.067s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1195,"lbm_read_time_us":12259,"lbm_reads_lt_1ms":472,"lbm_write_time_us":32504,"lbm_writes_lt_1ms":443,"mutex_wait_us":55,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":28800,"update_count":2000}
I20260812 06:17:54.031538  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=10.126437
I20260812 06:17:54.080403  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.049s	user 0.033s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":21434,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.080933  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:54.098558  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.017s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6862,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.099186  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:54.244426  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.145s	user 0.126s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":9281,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28302,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2000}
I20260812 06:17:54.245123  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=6.157687
I20260812 06:17:54.276963  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.032s	user 0.021s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10264,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:54.277768  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:54.291553  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":1600131,"delete_count":0,"lbm_write_time_us":4666,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":41,"reinsert_count":0,"update_count":195}
I20260812 06:17:54.292152  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.196750
I20260812 06:17:54.308333  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":2502679,"delete_count":0,"lbm_write_time_us":5075,"lbm_writes_lt_1ms":64,"reinsert_count":0,"update_count":305}
I20260812 06:17:54.309226  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:54.467535  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.158s	user 0.103s	sys 0.048s Metrics: {"cfile_cache_miss":333,"cfile_cache_miss_bytes":16528924,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":560,"lbm_read_time_us":13095,"lbm_reads_lt_1ms":373,"lbm_write_time_us":27900,"lbm_writes_lt_1ms":343,"mutex_wait_us":84,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":1500}
I20260812 06:17:54.468158  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=14.095187
I20260812 06:17:54.525249  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.057s	user 0.023s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19064,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.525993  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:54.537667  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.011s	user 0.004s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4521,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.538196  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushMRSOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:54.586248  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushMRSOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.048s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":1627,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1383,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:54.587251  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling LogGCOp(a1b4b509787841deadf7146518e0e6f1): free 124257187 bytes of WAL
I20260812 06:17:54.587574  7827 log_reader.cc:385] T a1b4b509787841deadf7146518e0e6f1: removed 12 log segments from log reader
I20260812 06:17:54.587638  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000002 (ops 7-11)
I20260812 06:17:54.587702  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000003 (ops 12-16)
I20260812 06:17:54.587740  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000004 (ops 17-21)
I20260812 06:17:54.587778  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000005 (ops 22-26)
I20260812 06:17:54.587826  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000006 (ops 27-30)
I20260812 06:17:54.587864  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000007 (ops 31-35)
I20260812 06:17:54.587924  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000008 (ops 36-40)
I20260812 06:17:54.587965  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000009 (ops 41-45)
I20260812 06:17:54.588016  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000010 (ops 46-50)
I20260812 06:17:54.588058  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000011 (ops 51-55)
I20260812 06:17:54.588107  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000012 (ops 56-60)
I20260812 06:17:54.588152  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000013 (ops 61-65)
I20260812 06:17:54.618265  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: LogGCOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:17:54.618701  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling UndoDeltaBlockGCOp(a1b4b509787841deadf7146518e0e6f1): 447 bytes on disk
I20260812 06:17:54.619264  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: UndoDeltaBlockGCOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:17:54.619807  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:54.642506  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.023s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4143685,"delete_count":0,"lbm_write_time_us":7322,"lbm_writes_lt_1ms":104,"reinsert_count":0,"update_count":505}
I20260812 06:17:54.643098  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:54.656687  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.013s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4061635,"delete_count":0,"lbm_write_time_us":5197,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:17:54.657269  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:54.902962  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.245s	user 0.158s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938787,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":201,"lbm_read_time_us":14441,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":773,"lbm_write_time_us":45735,"lbm_writes_lt_1ms":743,"mutex_wait_us":29,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6656,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:17:54.904433  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=14.095187
I20260812 06:17:54.958541  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.054s	user 0.019s	sys 0.032s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":25823,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.959408  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:54.978319  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.019s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5131,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.979038  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:55.151788  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.173s	user 0.117s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":467,"lbm_read_time_us":11632,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29875,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:55.152443  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=14.095187
I20260812 06:17:55.217904  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.065s	user 0.026s	sys 0.022s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":18237,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.218456  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:55.227012  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.008s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1928330,"delete_count":0,"lbm_write_time_us":2003,"lbm_writes_lt_1ms":50,"reinsert_count":0,"update_count":235}
I20260812 06:17:55.227417  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.196750
I20260812 06:17:55.233935  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.006s	user 0.005s	sys 0.000s Metrics: {"bytes_written":2174479,"delete_count":0,"lbm_write_time_us":2170,"lbm_writes_lt_1ms":56,"reinsert_count":0,"update_count":265}
I20260812 06:17:55.234328  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:55.436074  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.202s	user 0.133s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733751,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":740,"lbm_read_time_us":11985,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33318,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:17:55.436816  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=14.095187
I20260812 06:17:55.498904  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.062s	user 0.040s	sys 0.020s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":22853,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.499482  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:55.510541  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4289,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.511003  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:55.685808  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.175s	user 0.105s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733728,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":192,"lbm_read_time_us":12082,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29265,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:17:55.686455  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=14.095187
I20260812 06:17:55.755584  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.069s	user 0.025s	sys 0.035s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24214,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.756253  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:55.767951  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4725,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.768451  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:55.938125  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.169s	user 0.116s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733726,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":250,"lbm_read_time_us":12305,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28576,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24320,"update_count":2500}
I20260812 06:17:55.939041  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=11.118625
I20260812 06:17:55.975144  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.035s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15634,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:55.975733  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:55.990278  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5363,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:55.990763  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:56.131108  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.140s	user 0.125s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631304,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":116,"lbm_read_time_us":10404,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25769,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:56.132143  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=10.126437
I20260812 06:17:56.168684  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.036s	user 0.016s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15364,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.169246  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:56.185887  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.016s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5097,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.186592  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushMRSOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:56.218618  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushMRSOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.032s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":91,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":1452,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2044,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:56.219959  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling LogGCOp(a1b4b509787841deadf7146518e0e6f1): free 120553394 bytes of WAL
I20260812 06:17:56.220237  7827 log_reader.cc:385] T a1b4b509787841deadf7146518e0e6f1: removed 12 log segments from log reader
I20260812 06:17:56.220331  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000014 (ops 66-70)
I20260812 06:17:56.220392  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000015 (ops 71-75)
I20260812 06:17:56.220454  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000016 (ops 76-80)
I20260812 06:17:56.220505  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000017 (ops 81-85)
I20260812 06:17:56.220571  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000018 (ops 86-90)
I20260812 06:17:56.220618  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000019 (ops 91-94)
I20260812 06:17:56.220670  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000020 (ops 95-99)
I20260812 06:17:56.220716  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000021 (ops 100-104)
I20260812 06:17:56.220757  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000022 (ops 105-109)
I20260812 06:17:56.220794  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000023 (ops 110-114)
I20260812 06:17:56.220834  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000024 (ops 115-118)
I20260812 06:17:56.220880  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000025 (ops 119-123)
I20260812 06:17:56.247786  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: LogGCOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.028s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:17:56.248319  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling UndoDeltaBlockGCOp(a1b4b509787841deadf7146518e0e6f1): 483 bytes on disk
I20260812 06:17:56.248986  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: UndoDeltaBlockGCOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:17:56.249763  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=4.173312
I20260812 06:17:56.272418  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.023s	user 0.016s	sys 0.004s Metrics: {"bytes_written":6358991,"delete_count":0,"lbm_write_time_us":9546,"lbm_writes_lt_1ms":158,"reinsert_count":0,"update_count":775}
I20260812 06:17:56.273085  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:56.283749  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":1846277,"delete_count":0,"lbm_write_time_us":3259,"lbm_writes_lt_1ms":48,"reinsert_count":0,"update_count":225}
I20260812 06:17:56.284255  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling LogGCOp(a1b4b509787841deadf7146518e0e6f1): free 12017983 bytes of WAL
I20260812 06:17:56.284524  7827 log_reader.cc:385] T a1b4b509787841deadf7146518e0e6f1: removed 1 log segments from log reader
I20260812 06:17:56.284633  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000026 (ops 124-128)
I20260812 06:17:56.287971  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: LogGCOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:56.288388  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:56.463454  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.175s	user 0.133s	sys 0.041s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836320,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":850,"lbm_read_time_us":10455,"lbm_reads_lt_1ms":666,"lbm_write_time_us":37757,"lbm_writes_lt_1ms":643,"mutex_wait_us":555,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":25216,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:17:56.464278  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=14.095187
I20260812 06:17:56.514050  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.050s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21458,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:56.514715  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:56.533876  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.019s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6808,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.534705  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:56.705191  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.169s	user 0.127s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":208,"lbm_read_time_us":11189,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31825,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:17:56.705953  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=14.095187
I20260812 06:17:56.761509  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.055s	user 0.042s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22476,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:56.762074  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:56.774524  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4418,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.775079  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:56.929402  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.154s	user 0.127s	sys 0.016s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":379,"lbm_read_time_us":9163,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30464,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":93824,"update_count":2500}
I20260812 06:17:56.930217  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=14.095187
I20260812 06:17:56.983436  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.053s	user 0.022s	sys 0.021s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20646,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:56.984166  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:56.996345  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4641,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.996925  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:57.155018  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.158s	user 0.109s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1263,"lbm_read_time_us":9856,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31620,"lbm_writes_lt_1ms":543,"mutex_wait_us":318,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:17:57.155833  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=12.110812
I20260812 06:17:57.203815  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.048s	user 0.025s	sys 0.019s Metrics: {"bytes_written":13620265,"delete_count":0,"lbm_write_time_us":18824,"lbm_writes_lt_1ms":335,"reinsert_count":0,"update_count":1660}
I20260812 06:17:57.204387  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.196750
I20260812 06:17:57.225994  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.021s	user 0.007s	sys 0.001s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":3450,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:17:57.226442  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:57.236686  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3907,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.237108  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:57.408870  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.172s	user 0.124s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733814,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":240,"lbm_read_time_us":12147,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28516,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":60288,"update_count":2500}
I20260812 06:17:57.409577  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=14.095187
I20260812 06:17:57.473529  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.064s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":21794,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.474066  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:57.484864  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4023,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.485337  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:57.658991  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.173s	user 0.105s	sys 0.066s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733719,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":246,"lbm_read_time_us":12196,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31510,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2500}
I20260812 06:17:57.659598  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=11.118625
I20260812 06:17:57.706473  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.047s	user 0.017s	sys 0.028s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16652,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:57.707072  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:57.718832  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4111,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:57.719496  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushMRSOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:57.751735  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushMRSOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1674,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1806,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:57.752952  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling LogGCOp(a1b4b509787841deadf7146518e0e6f1): free 121006707 bytes of WAL
I20260812 06:17:57.753347  7827 log_reader.cc:385] T a1b4b509787841deadf7146518e0e6f1: removed 12 log segments from log reader
I20260812 06:17:57.753463  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000027 (ops 129-133)
I20260812 06:17:57.753531  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000028 (ops 134-138)
I20260812 06:17:57.753595  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000029 (ops 139-143)
I20260812 06:17:57.753661  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000030 (ops 144-148)
I20260812 06:17:57.753726  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000031 (ops 149-153)
I20260812 06:17:57.753796  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000032 (ops 154-158)
I20260812 06:17:57.753862  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000033 (ops 159-163)
I20260812 06:17:57.753940  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000034 (ops 164-168)
I20260812 06:17:57.753986  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000035 (ops 169-173)
I20260812 06:17:57.754033  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000036 (ops 174-178)
I20260812 06:17:57.754096  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000037 (ops 179-182)
I20260812 06:17:57.754169  7827 log.cc:1079] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/a1b4b509787841deadf7146518e0e6f1/wal-000000038 (ops 183-187)
I20260812 06:17:57.798058  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: LogGCOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.045s	user 0.000s	sys 0.043s Metrics: {}
I20260812 06:17:57.798646  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling UndoDeltaBlockGCOp(a1b4b509787841deadf7146518e0e6f1): 482 bytes on disk
I20260812 06:17:57.799355  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: UndoDeltaBlockGCOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":101,"lbm_reads_lt_1ms":4}
I20260812 06:17:57.800133  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:57.835547  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.035s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7065,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.836046  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:57.856303  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.020s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6809,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.856890  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:58.092921  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.235s	user 0.170s	sys 0.058s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836366,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":662,"dirs.run_cpu_time_us":643,"dirs.run_wall_time_us":3763,"lbm_read_time_us":16059,"lbm_reads_lt_1ms":666,"lbm_write_time_us":40506,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5888,"thread_start_us":95,"threads_started":1,"update_count":3000}
I20260812 06:17:58.093791  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=14.095187
I20260812 06:17:58.157210  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.063s	user 0.040s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21466,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.157704  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1): perf score=2.188937
I20260812 06:17:58.170676  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: FlushDeltaMemStoresOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4590,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.172037  7894 maintenance_manager.cc:419] P aefa07cfa3734999a2a3a5d96cae6f6a: Scheduling MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1): perf score=1.000000
I20260812 06:17:58.220671  7702 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.275s	user 1.946s	sys 0.169s
I20260812 06:17:58.318696  7702 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.097s	user 0.002s	sys 0.000s
I20260812 06:17:58.319379  7702 tablet_server.cc:179] TabletServer@127.7.133.129:0 shutting down...
I20260812 06:17:58.368471  7827 maintenance_manager.cc:643] P aefa07cfa3734999a2a3a5d96cae6f6a: MajorDeltaCompactionOp(a1b4b509787841deadf7146518e0e6f1) complete. Timing: real 0.196s	user 0.134s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1209,"lbm_read_time_us":15654,"lbm_reads_lt_1ms":568,"lbm_write_time_us":36152,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":350,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2500}
I20260812 06:17:58.369263  7702 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:58.369719  7702 tablet_replica.cc:333] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a: stopping tablet replica
I20260812 06:17:58.369998  7702 raft_consensus.cc:2243] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:58.370270  7702 raft_consensus.cc:2272] T a1b4b509787841deadf7146518e0e6f1 P aefa07cfa3734999a2a3a5d96cae6f6a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:58.389110  7702 tablet_server.cc:196] TabletServer@127.7.133.129:0 shutdown complete.
I20260812 06:17:58.415904  7702 master.cc:562] Master@127.7.133.190:39723 shutting down...
I20260812 06:17:58.420480  7702 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:58.420727  7702 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:58.420821  7702 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0f4f5321adf94665b2eb5ee9ba304993: stopping tablet replica
I20260812 06:17:58.433495  7702 master.cc:584] Master@127.7.133.190:39723 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5894 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:58.541266  7702 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.7.133.190:38591
I20260812 06:17:58.541829  7702 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:58.544193  7930 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:17:58.544301  7702 server_base.cc:1061] running on GCE node
W20260812 06:17:58.544317  7928 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:17:58.544512  7932 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:17:58.544768  7702 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:58.544821  7702 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:17:58.544837  7702 hybrid_clock.cc:648] HybridClock initialized: now 1786515478544837 us; error 0 us; skew 500 ppm
I20260812 06:17:58.545744  7702 webserver.cc:533] Webserver started at http://127.7.133.190:43323/ using document root <none> and password file <none>
I20260812 06:17:58.545931  7702 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:58.545993  7702 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:58.546089  7702 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:58.546532  7702 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/master-0-root/instance:
uuid: "ede3ce736b5d4d6a97fd146b265a4e58"
format_stamp: "Formatted at 2026-08-12 06:17:58 on dist-test-slave-8n49"
I20260812 06:17:58.548147  7702 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:58.549273  7938 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:17:58.549595  7702 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:58.549700  7702 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/master-0-root
uuid: "ede3ce736b5d4d6a97fd146b265a4e58"
format_stamp: "Formatted at 2026-08-12 06:17:58 on dist-test-slave-8n49"
I20260812 06:17:58.549796  7702 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-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:17:58.573455  7702 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:58.573931  7702 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:58.578431  7702 rpc_server.cc:307] RPC server started. Bound to: 127.7.133.190:38591
I20260812 06:17:58.580433  8000 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.133.190:38591 every 8 connection(s)
I20260812 06:17:58.583178  8001 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:17:58.585109  8001 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58: Bootstrap starting.
I20260812 06:17:58.585929  8001 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:58.586982  8001 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58: No bootstrap required, opened a new log
I20260812 06:17:58.587419  8001 raft_consensus.cc:359] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ede3ce736b5d4d6a97fd146b265a4e58" member_type: VOTER }
I20260812 06:17:58.587539  8001 raft_consensus.cc:385] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:58.587564  8001 raft_consensus.cc:740] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ede3ce736b5d4d6a97fd146b265a4e58, State: Initialized, Role: FOLLOWER
I20260812 06:17:58.587741  8001 consensus_queue.cc:260] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [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: "ede3ce736b5d4d6a97fd146b265a4e58" member_type: VOTER }
I20260812 06:17:58.587832  8001 raft_consensus.cc:399] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:58.587857  8001 raft_consensus.cc:493] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:58.587913  8001 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:58.588694  8001 raft_consensus.cc:515] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ede3ce736b5d4d6a97fd146b265a4e58" member_type: VOTER }
I20260812 06:17:58.588809  8001 leader_election.cc:304] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [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: ede3ce736b5d4d6a97fd146b265a4e58; no voters: 
I20260812 06:17:58.589053  8001 leader_election.cc:290] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:58.589227  8005 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:58.589448  8005 raft_consensus.cc:697] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [term 1 LEADER]: Becoming Leader. State: Replica: ede3ce736b5d4d6a97fd146b265a4e58, State: Running, Role: LEADER
I20260812 06:17:58.589541  8001 sys_catalog.cc:565] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:58.589634  8005 consensus_queue.cc:237] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [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: "ede3ce736b5d4d6a97fd146b265a4e58" member_type: VOTER }
I20260812 06:17:58.590154  8006 sys_catalog.cc:455] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ede3ce736b5d4d6a97fd146b265a4e58" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ede3ce736b5d4d6a97fd146b265a4e58" member_type: VOTER } }
I20260812 06:17:58.590277  8006 sys_catalog.cc:458] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:58.590169  8007 sys_catalog.cc:455] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [sys.catalog]: SysCatalogTable state changed. Reason: New leader ede3ce736b5d4d6a97fd146b265a4e58. Latest consensus state: current_term: 1 leader_uuid: "ede3ce736b5d4d6a97fd146b265a4e58" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ede3ce736b5d4d6a97fd146b265a4e58" member_type: VOTER } }
I20260812 06:17:58.590389  8007 sys_catalog.cc:458] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:58.590919  8013 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:58.591670  8013 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:58.591881  7702 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:58.593753  8013 catalog_manager.cc:1383] Generated new cluster ID: 9f88270a660c429984a06261813e48a0
I20260812 06:17:58.593815  8013 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:58.614120  8013 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:58.614677  8013 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:58.624436  8013 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58: Generated new TSK 0
I20260812 06:17:58.624641  8013 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:58.656529  7702 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:58.659072  8025 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:58.659106  8027 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:17:58.659107  8024 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:17:58.659415  7702 server_base.cc:1061] running on GCE node
I20260812 06:17:58.659617  7702 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:58.659673  7702 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:17:58.659706  7702 hybrid_clock.cc:648] HybridClock initialized: now 1786515478659705 us; error 0 us; skew 500 ppm
I20260812 06:17:58.660640  7702 webserver.cc:533] Webserver started at http://127.7.133.129:41889/ using document root <none> and password file <none>
I20260812 06:17:58.660832  7702 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:58.660905  7702 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:58.660986  7702 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:58.661412  7702 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/instance:
uuid: "1c7e5cf3a61649f68118627c058ed501"
format_stamp: "Formatted at 2026-08-12 06:17:58 on dist-test-slave-8n49"
I20260812 06:17:58.663048  7702 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:58.664119  8032 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:17:58.664487  7702 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:58.664620  7702 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root
uuid: "1c7e5cf3a61649f68118627c058ed501"
format_stamp: "Formatted at 2026-08-12 06:17:58 on dist-test-slave-8n49"
I20260812 06:17:58.664721  7702 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-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:17:58.687402  7702 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:58.687846  7702 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:58.688200  7702 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:58.688719  7702 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:58.688782  7702 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:58.688840  7702 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:58.688892  7702 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:58.693871  7702 rpc_server.cc:307] RPC server started. Bound to: 127.7.133.129:37969
I20260812 06:17:58.694990  8102 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.133.129:37969 every 8 connection(s)
I20260812 06:17:58.699566  8104 heartbeater.cc:344] Connected to a master server at 127.7.133.190:38591
I20260812 06:17:58.699666  8104 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:58.699849  8104 heartbeater.cc:507] Master 127.7.133.190:38591 requested a full tablet report, sending...
I20260812 06:17:58.700510  7959 ts_manager.cc:194] Registered new tserver with Master: 1c7e5cf3a61649f68118627c058ed501 (127.7.133.129:37969)
I20260812 06:17:58.701283  7702 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.006670914s
I20260812 06:17:58.701324  7959 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60882
I20260812 06:17:58.708859  7959 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60884:
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:17:58.717517  8063 tablet_service.cc:1511] Processing CreateTablet for tablet b75a8b78ed844b03b37d8ba3f26a5e5f (DEFAULT_TABLE table=heavy-update-compaction-test [id=2422786dabe44056b72c462c32a8e879]), partition=
I20260812 06:17:58.717826  8063 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b75a8b78ed844b03b37d8ba3f26a5e5f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:58.720101  8119 tablet_bootstrap.cc:492] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Bootstrap starting.
I20260812 06:17:58.721086  8119 tablet_bootstrap.cc:654] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:58.722352  8119 tablet_bootstrap.cc:492] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: No bootstrap required, opened a new log
I20260812 06:17:58.722481  8119 ts_tablet_manager.cc:1403] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:58.723032  8119 raft_consensus.cc:359] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c7e5cf3a61649f68118627c058ed501" member_type: VOTER last_known_addr { host: "127.7.133.129" port: 37969 } }
I20260812 06:17:58.723131  8119 raft_consensus.cc:385] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:58.723155  8119 raft_consensus.cc:740] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1c7e5cf3a61649f68118627c058ed501, State: Initialized, Role: FOLLOWER
I20260812 06:17:58.723317  8119 consensus_queue.cc:260] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501 [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: "1c7e5cf3a61649f68118627c058ed501" member_type: VOTER last_known_addr { host: "127.7.133.129" port: 37969 } }
I20260812 06:17:58.723421  8119 raft_consensus.cc:399] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:58.723474  8119 raft_consensus.cc:493] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:58.723531  8119 raft_consensus.cc:3060] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:58.724339  8119 raft_consensus.cc:515] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c7e5cf3a61649f68118627c058ed501" member_type: VOTER last_known_addr { host: "127.7.133.129" port: 37969 } }
I20260812 06:17:58.724490  8119 leader_election.cc:304] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501 [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: 1c7e5cf3a61649f68118627c058ed501; no voters: 
I20260812 06:17:58.724757  8119 leader_election.cc:290] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:58.724874  8121 raft_consensus.cc:2804] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:58.725128  8119 ts_tablet_manager.cc:1434] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:17:58.725167  8121 raft_consensus.cc:697] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501 [term 1 LEADER]: Becoming Leader. State: Replica: 1c7e5cf3a61649f68118627c058ed501, State: Running, Role: LEADER
I20260812 06:17:58.725198  8104 heartbeater.cc:499] Master 127.7.133.190:38591 was elected leader, sending a full tablet report...
I20260812 06:17:58.725363  8121 consensus_queue.cc:237] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501 [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: "1c7e5cf3a61649f68118627c058ed501" member_type: VOTER last_known_addr { host: "127.7.133.129" port: 37969 } }
I20260812 06:17:58.726684  7959 catalog_manager.cc:5719] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501 reported cstate change: term changed from 0 to 1, leader changed from <none> to 1c7e5cf3a61649f68118627c058ed501 (127.7.133.129). New cstate: current_term: 1 leader_uuid: "1c7e5cf3a61649f68118627c058ed501" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1c7e5cf3a61649f68118627c058ed501" member_type: VOTER last_known_addr { host: "127.7.133.129" port: 37969 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:58.785166  7702 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.010s	sys 0.012s
I20260812 06:17:58.945434  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushMRSOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=19.054940
I20260812 06:17:59.115239  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushMRSOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.170s	user 0.131s	sys 0.036s Metrics: {"bytes_written":13004891,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":185,"dirs.run_wall_time_us":836,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41353,"lbm_writes_lt_1ms":784,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1585}
I20260812 06:17:59.115948  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling LogGCOp(b75a8b78ed844b03b37d8ba3f26a5e5f): free 20743880 bytes of WAL
I20260812 06:17:59.116175  8038 log_reader.cc:385] T b75a8b78ed844b03b37d8ba3f26a5e5f: removed 2 log segments from log reader
I20260812 06:17:59.116238  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000001 (ops 1-6)
I20260812 06:17:59.116356  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000002 (ops 7-11)
I20260812 06:17:59.120620  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: LogGCOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {"spinlock_wait_cycles":38656}
I20260812 06:17:59.121143  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling UndoDeltaBlockGCOp(b75a8b78ed844b03b37d8ba3f26a5e5f): 16821648 bytes on disk
I20260812 06:17:59.121570  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: UndoDeltaBlockGCOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:17:59.122035  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=3.181125
I20260812 06:17:59.134253  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4553930,"delete_count":0,"lbm_write_time_us":4805,"lbm_writes_lt_1ms":114,"reinsert_count":0,"update_count":555}
I20260812 06:17:59.134683  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.196750
I20260812 06:17:59.141782  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.007s	user 0.006s	sys 0.000s Metrics: {"bytes_written":2543704,"delete_count":0,"lbm_write_time_us":2403,"lbm_writes_lt_1ms":65,"reinsert_count":0,"update_count":310}
I20260812 06:17:59.142238  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:17:59.310974  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.169s	user 0.129s	sys 0.040s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405520,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":319,"lbm_read_time_us":12369,"lbm_reads_lt_1ms":559,"lbm_write_time_us":27918,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":3584,"thread_start_us":304,"threads_started":5,"update_count":2450}
I20260812 06:17:59.311537  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=14.095187
I20260812 06:17:59.368420  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.057s	user 0.042s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26381,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.369084  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:17:59.384887  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5711,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.385437  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:17:59.564769  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.179s	user 0.108s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":866,"lbm_read_time_us":12620,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28963,"lbm_writes_lt_1ms":543,"mutex_wait_us":269,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:17:59.565516  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=14.095187
I20260812 06:17:59.626389  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.061s	user 0.030s	sys 0.029s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22523,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.627043  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:17:59.639035  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4606,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.639721  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:17:59.835588  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.196s	user 0.148s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":413,"lbm_read_time_us":14894,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30609,"lbm_writes_lt_1ms":543,"mutex_wait_us":98,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:59.836675  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=14.095187
I20260812 06:17:59.901746  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.065s	user 0.023s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20063,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.902457  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:17:59.914857  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4879,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.915352  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:18:00.109807  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.194s	user 0.138s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":448,"lbm_read_time_us":12627,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32173,"lbm_writes_lt_1ms":543,"mutex_wait_us":81,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:00.110520  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=14.095187
I20260812 06:18:00.173290  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.063s	user 0.035s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":33165,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":399,"reinsert_count":0,"update_count":2000}
I20260812 06:18:00.173882  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:18:00.198348  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.024s	user 0.005s	sys 0.016s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5743,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.199218  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:18:00.384879  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.185s	user 0.116s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":161,"lbm_read_time_us":13627,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28066,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:18:00.385697  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=14.095187
I20260812 06:18:00.429205  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.043s	user 0.030s	sys 0.013s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":18593,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:00.429754  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:18:00.453491  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.024s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4184708,"delete_count":0,"lbm_write_time_us":4861,"lbm_writes_lt_1ms":105,"reinsert_count":0,"update_count":510}
I20260812 06:18:00.453944  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:18:00.473085  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.019s	user 0.010s	sys 0.009s Metrics: {"bytes_written":4020609,"delete_count":0,"lbm_write_time_us":3831,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:18:00.473623  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushMRSOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:18:00.514681  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushMRSOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.041s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":88,"dirs.run_cpu_time_us":246,"dirs.run_wall_time_us":1466,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1383,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:00.515327  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling LogGCOp(b75a8b78ed844b03b37d8ba3f26a5e5f): free 124257253 bytes of WAL
I20260812 06:18:00.515592  8038 log_reader.cc:385] T b75a8b78ed844b03b37d8ba3f26a5e5f: removed 12 log segments from log reader
I20260812 06:18:00.515653  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000003 (ops 12-16)
I20260812 06:18:00.515691  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000004 (ops 17-21)
I20260812 06:18:00.515719  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000005 (ops 22-26)
I20260812 06:18:00.515748  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000006 (ops 27-30)
I20260812 06:18:00.515774  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000007 (ops 31-35)
I20260812 06:18:00.515807  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000008 (ops 36-40)
I20260812 06:18:00.515837  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000009 (ops 41-45)
I20260812 06:18:00.515863  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000010 (ops 46-50)
I20260812 06:18:00.515893  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000011 (ops 51-55)
I20260812 06:18:00.515923  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000012 (ops 56-60)
I20260812 06:18:00.515955  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000013 (ops 61-65)
I20260812 06:18:00.515990  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000014 (ops 66-70)
I20260812 06:18:00.544520  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: LogGCOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.029s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:18:00.544970  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling UndoDeltaBlockGCOp(b75a8b78ed844b03b37d8ba3f26a5e5f): 472 bytes on disk
I20260812 06:18:00.545398  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: UndoDeltaBlockGCOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:18:00.545868  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:18:00.567880  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.022s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4783,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.568395  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:18:00.582688  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5450,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.583223  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:18:00.837038  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.254s	user 0.182s	sys 0.071s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37123271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":508,"lbm_read_time_us":15856,"lbm_reads_lt_1ms":875,"lbm_write_time_us":43656,"lbm_writes_lt_1ms":843,"mutex_wait_us":20,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":9856,"thread_start_us":83,"threads_started":1,"update_count":4000}
I20260812 06:18:00.839843  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=19.056125
I20260812 06:18:00.908249  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.068s	user 0.028s	sys 0.024s Metrics: {"bytes_written":20922553,"delete_count":0,"lbm_write_time_us":25011,"lbm_writes_lt_1ms":513,"reinsert_count":0,"update_count":2550}
I20260812 06:18:00.908756  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=6.157687
I20260812 06:18:00.935674  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.027s	user 0.014s	sys 0.009s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":11225,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:00.936311  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:18:01.136781  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.200s	user 0.146s	sys 0.051s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":33020506,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":268,"lbm_read_time_us":12044,"lbm_reads_lt_1ms":764,"lbm_write_time_us":43622,"lbm_writes_lt_1ms":743,"mutex_wait_us":21,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":3500}
I20260812 06:18:01.137552  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=15.087375
I20260812 06:18:01.181624  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.043s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":19025,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:01.182478  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:18:01.199138  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5668,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:01.199787  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:18:01.353281  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.153s	user 0.123s	sys 0.026s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815670,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":86,"lbm_read_time_us":9779,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28882,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:01.354082  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=14.095187
I20260812 06:18:01.409262  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.055s	user 0.034s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24250,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:01.409860  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:18:01.427395  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6581,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.428146  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:18:01.593261  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.165s	user 0.109s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":657,"lbm_read_time_us":10523,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28633,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":880384,"update_count":2500}
I20260812 06:18:01.593778  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=14.095187
I20260812 06:18:01.651052  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.057s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22977,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:01.651608  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:18:01.814056  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.162s	user 0.112s	sys 0.039s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713154,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":268,"lbm_read_time_us":9288,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25930,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2000}
I20260812 06:18:01.814867  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=14.095187
I20260812 06:18:01.866294  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.051s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20862,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:01.866822  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:18:01.877547  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4140,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.878290  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushMRSOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:18:01.921506  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushMRSOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.043s	user 0.036s	sys 0.001s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":270,"dirs.run_wall_time_us":1661,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1690,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:01.922495  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling LogGCOp(b75a8b78ed844b03b37d8ba3f26a5e5f): free 117302580 bytes of WAL
I20260812 06:18:01.922797  8038 log_reader.cc:385] T b75a8b78ed844b03b37d8ba3f26a5e5f: removed 12 log segments from log reader
I20260812 06:18:01.922878  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000015 (ops 71-75)
I20260812 06:18:01.922940  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000016 (ops 76-80)
I20260812 06:18:01.923008  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000017 (ops 81-85)
I20260812 06:18:01.923053  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000018 (ops 86-90)
I20260812 06:18:01.923103  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000019 (ops 91-95)
I20260812 06:18:01.923146  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000020 (ops 96-100)
I20260812 06:18:01.923187  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000021 (ops 101-104)
I20260812 06:18:01.923228  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000022 (ops 105-109)
I20260812 06:18:01.923270  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000023 (ops 110-114)
I20260812 06:18:01.923311  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000024 (ops 115-118)
I20260812 06:18:01.923352  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000025 (ops 119-123)
I20260812 06:18:01.923393  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000026 (ops 124-128)
I20260812 06:18:01.948685  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: LogGCOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:01.949165  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling UndoDeltaBlockGCOp(b75a8b78ed844b03b37d8ba3f26a5e5f): 447 bytes on disk
I20260812 06:18:01.949841  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: UndoDeltaBlockGCOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":107,"lbm_reads_lt_1ms":4}
I20260812 06:18:01.950505  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:18:01.967777  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.017s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4148,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.968238  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:18:01.979039  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4039,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.979563  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:18:02.220719  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.241s	user 0.149s	sys 0.092s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020744,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":486,"lbm_read_time_us":16916,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38349,"lbm_writes_lt_1ms":743,"mutex_wait_us":80,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":109,"threads_started":1,"update_count":3500}
I20260812 06:18:02.221539  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=18.063937
I20260812 06:18:02.286947  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.065s	user 0.030s	sys 0.023s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":25115,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:02.287423  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:18:02.299192  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4275,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.299695  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:18:02.504855  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.205s	user 0.133s	sys 0.069s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1046,"lbm_read_time_us":14109,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34305,"lbm_writes_lt_1ms":643,"mutex_wait_us":378,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":3000}
I20260812 06:18:02.508813  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=14.095187
I20260812 06:18:02.558933  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.050s	user 0.027s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22113,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:02.559542  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:18:02.573318  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5486,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.573886  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:18:02.764591  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.190s	user 0.102s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":654,"lbm_read_time_us":12312,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31198,"lbm_writes_lt_1ms":543,"mutex_wait_us":123,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:18:02.765228  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=14.095187
I20260812 06:18:02.824244  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.059s	user 0.025s	sys 0.015s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":17484,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:18:02.824924  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:18:02.837056  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4363,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.837750  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:18:03.023195  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.185s	user 0.098s	sys 0.081s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815678,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":287,"lbm_read_time_us":12560,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31111,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":42240,"update_count":2500}
I20260812 06:18:03.023880  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=14.095187
I20260812 06:18:03.081938  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.058s	user 0.017s	sys 0.039s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":18406,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:03.082418  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:18:03.093199  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4216,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.093662  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:18:03.280825  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.187s	user 0.115s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":245,"lbm_read_time_us":12565,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30686,"lbm_writes_lt_1ms":543,"mutex_wait_us":70,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:18:03.281574  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=14.095187
I20260812 06:18:03.339217  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.057s	user 0.029s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26255,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:03.339730  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:18:03.360536  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.021s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5227,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.361088  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushMRSOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:18:03.392684  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushMRSOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.031s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1464,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1383,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:03.393388  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling LogGCOp(b75a8b78ed844b03b37d8ba3f26a5e5f): free 111786491 bytes of WAL
I20260812 06:18:03.393620  8038 log_reader.cc:385] T b75a8b78ed844b03b37d8ba3f26a5e5f: removed 11 log segments from log reader
I20260812 06:18:03.393662  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000027 (ops 129-132)
I20260812 06:18:03.393692  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000028 (ops 133-137)
I20260812 06:18:03.393759  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000029 (ops 138-142)
I20260812 06:18:03.393787  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000030 (ops 143-146)
I20260812 06:18:03.393824  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000031 (ops 147-151)
I20260812 06:18:03.393862  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000032 (ops 152-156)
I20260812 06:18:03.393900  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000033 (ops 157-161)
I20260812 06:18:03.393935  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000034 (ops 162-166)
I20260812 06:18:03.393973  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000035 (ops 167-171)
I20260812 06:18:03.394016  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000036 (ops 172-176)
I20260812 06:18:03.394057  8038 log.cc:1079] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: Deleting log segment in path: /tmp/dist-test-taskxLG0gr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472623567-7702-0/minicluster-data/ts-0-root/wals/b75a8b78ed844b03b37d8ba3f26a5e5f/wal-000000037 (ops 177-181)
I20260812 06:18:03.419567  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: LogGCOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:03.419950  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=3.181125
I20260812 06:18:03.441969  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.022s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7219,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:03.442427  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling UndoDeltaBlockGCOp(b75a8b78ed844b03b37d8ba3f26a5e5f): 448 bytes on disk
I20260812 06:18:03.442818  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: UndoDeltaBlockGCOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:03.443383  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:18:03.452913  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3505,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:03.453356  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:18:03.696801  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.243s	user 0.164s	sys 0.074s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020736,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":984,"lbm_read_time_us":13940,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43383,"lbm_writes_lt_1ms":743,"mutex_wait_us":176,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":106,"threads_started":1,"update_count":3500}
I20260812 06:18:03.697680  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=18.063937
I20260812 06:18:03.768726  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.071s	user 0.037s	sys 0.027s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":31350,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":500,"reinsert_count":0,"update_count":2500}
I20260812 06:18:03.769218  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=2.188937
I20260812 06:18:03.779579  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: FlushDeltaMemStoresOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3931,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.780103  8106 maintenance_manager.cc:419] P 1c7e5cf3a61649f68118627c058ed501: Scheduling MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f): perf score=1.000000
I20260812 06:18:03.815102  7702 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.030s	user 1.788s	sys 0.230s
I20260812 06:18:03.889407  7702 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.074s	user 0.004s	sys 0.000s
I20260812 06:18:03.890067  7702 tablet_server.cc:179] TabletServer@127.7.133.129:0 shutting down...
I20260812 06:18:03.952425  8038 maintenance_manager.cc:643] P 1c7e5cf3a61649f68118627c058ed501: MajorDeltaCompactionOp(b75a8b78ed844b03b37d8ba3f26a5e5f) complete. Timing: real 0.172s	user 0.132s	sys 0.040s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":311,"lbm_read_time_us":14002,"lbm_reads_lt_1ms":668,"lbm_write_time_us":30406,"lbm_writes_lt_1ms":643,"mutex_wait_us":50,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":3000}
I20260812 06:18:03.953233  7702 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:03.953478  7702 tablet_replica.cc:333] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501: stopping tablet replica
I20260812 06:18:03.953629  7702 raft_consensus.cc:2243] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:03.953824  7702 raft_consensus.cc:2272] T b75a8b78ed844b03b37d8ba3f26a5e5f P 1c7e5cf3a61649f68118627c058ed501 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:03.959326  7702 tablet_server.cc:196] TabletServer@127.7.133.129:0 shutdown complete.
I20260812 06:18:04.005908  7702 master.cc:562] Master@127.7.133.190:38591 shutting down...
I20260812 06:18:04.009745  7702 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:04.009934  7702 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:04.009991  7702 tablet_replica.cc:333] T 00000000000000000000000000000000 P ede3ce736b5d4d6a97fd146b265a4e58: stopping tablet replica
I20260812 06:18:04.022445  7702 master.cc:584] Master@127.7.133.190:38591 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5584 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11479 ms total)

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